Hello, On Mon, 2021-08-02 at 11:14 -0700, Bhaumik Bhatt wrote: > On 2021-08-02 09:33 AM, Loic Poulain wrote: > > > > On Fri, 30 Jul 2021 at 19:52, Thomas Perrot < > > > > thomas.perrot@xxxxxxxxxxx> wrote: > > > > > > > > > > Hello, > > > > > > > > > > I’m trying to use the MHI driver with a Sierra Wireless > > > > > AirPrime > > > > > EM919X > > > > > connected to an NXP i.MX6DL through a PCIe gen2 bus, on 5.13.6, > > > > > but > > > > > the > > > > > device initialisation fails, as follows: > > > > > > > > > > [ 3.029401] mhi-pci-generic 0000:01:00.0: BAR 0: assigned > > > > > [mem > > > > > 0x01100000-0x01100fff 64bit] > > > > > [ 3.041095] mhi-pci-generic 0000:01:00.0: enabling device > > > > > (0140 -> > > > > > 0142) > > > > > [ 3.118299] mhi mhi0: Requested to power ON > > > > > [ 11.370361] mhi mhi0: Power on setup success > > > > > [ 11.372503] mhi mhi0: Wait for device to enter SBL or > > > > > Mission mode > > > > > [ 15.664068] mhi-pci-generic 0000:01:00.0: failed to suspend > > > > > device: > > > > > -16 > > > > > [ 22.619948] mhi-pci-generic 0000:01:00.0: refused to change > > > > > power > > > > > state from D3hot to D0 > > > > > [ 57.289998] mhi-pci-generic 0000:01:00.0: can't change power > > > > > state > > > > > from D3hot to D0 (config space inaccessible) > > > > > [ 73.769675] mhi-pci-generic 0000:01:00.0: can't change power > > > > > state > > > > > from D3cold to D0 (config space inaccessible) > > > > > [ 73.780188] mhi-pci-generic 0000:01:00.0: can't change power > > > > > state > > > > > from D3hot to D0 (config space inaccessible) > > > > > [ 73.836150] PC is at mhi_pci_read_reg+0xc/0x14 > > > > > [ 73.840642] LR is at mhi_get_mhi_state+0x2c/0x5c > > > > > [ 74.121120] [<c05dcaf4>] (mhi_pci_read_reg) from > > > > > [<c05d754c>] > > > > > (mhi_get_mhi_state+0x2c/0x5c) > > > > > [ 74.129529] [<c05d754c>] (mhi_get_mhi_state) from > > > > > [<c05da440>] > > > > > (mhi_pm_resume+0x38/0x298) > > > > > [ 74.137754] [<c05da440>] (mhi_pm_resume) from [<c05dcbd0>] > > > > > (mhi_pci_runtime_resume+0x70/0xe0) > > > > > [ 74.146326] [<c05dcbd0>] (mhi_pci_runtime_resume) from > > > > > [<c0604da0>] > > > > > (pci_pm_runtime_resume+0x84/0xa0) > > > > > > > > > > Do you have any idea where the issue might come from? > > > > > > > > > > MHI seems to enter in READY state and waiting to enter in SBL > > > > > or > > > > > Mission mode when the issue occurs, the host can start MHI > > > > > initialization by programming MMIO registers and sets the > > > > > device into > > > > > MHI_M0 state. > > > > > > > > runtime-pm is only enabled when the device is in mission mode, so > > > > the > > > > device has likely been successfully initialized, It is just that > > > > there > > > > is no info message indicating initialization completion and we > > > > should > > > > probably add that. I think maybe about some PCIe suspend/resume > > > > issues, could you try disabling runtime-pm for that device? or > > > > simply > > > > comment `pm_runtime_allow` call? > > > > > > Thanks for your help, I disabled the power management, I obtains > > > the > > > following trace: > > > > > > [ 0.000000] Booting Linux on physical CPU 0x0 > > > [ 0.000000] Linux version 5.13.6 (arm-oe-linux-gnueabi-gcc (GCC) > > > 9.2.0, GNU ld (GNU Binutils) 2.32.0.20190204) #1 SMP Mon Aug 2 > > > 14:27:03 > > > UTC 2021 > > > [ 0.000000] CPU: ARMv7 Processor [412fc09a] revision 10 (ARMv7), > > > cr=10c5387d > > > [ 0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT > > > aliasing > > > instruction cache > > > [ 0.000000] OF: fdt: Machine model: i.MX6 Duallite module > > > [ 0.000000] Memory policy: Data cache writealloc > > > [ 0.000000] cma: Reserved 64 MiB at 0x4c000000 > > > [ 0.000000] Zone ranges: > > > [ 0.000000] Normal [mem 0x0000000010000000- > > > 0x000000003fffffff] > > > [ 0.000000] HighMem [mem 0x0000000040000000- > > > 0x000000004fffffff] > > > [ 0.000000] Movable zone start for each node > > > [ 0.000000] Early memory node ranges > > > [ 0.000000] node 0: [mem 0x0000000010000000- > > > 0x000000004fffffff] > > > [ 0.000000] Initmem setup node 0 [mem 0x0000000010000000- > > > 0x000000004fffffff] > > > [ 0.000000] On node 0 totalpages: 262144 > > > [ 0.000000] Normal zone: 1536 pages used for memmap > > > [ 0.000000] Normal zone: 0 pages reserved > > > [ 0.000000] Normal zone: 196608 pages, LIFO batch:63 > > > [ 0.000000] HighMem zone: 65536 pages, LIFO batch:15 > > > [ 0.000000] percpu: Embedded 20 pages/cpu s52396 r8192 d21332 > > > u81920 > > > [ 0.000000] pcpu-alloc: s52396 r8192 d21332 u81920 alloc=20*4096 > > > [ 0.000000] pcpu-alloc: [0] 0 [0] 1 > > > [ 0.000000] Built 1 zonelists, mobility grouping on. Total > > > pages: > > > 260608 > > > [ 0.000000] Kernel command line: console=ttymxc3,115200n8 > > > loglevel=8 > > > root=/dev/nfs ip=10.0.0.2:255.255.255.0 > > > nfsroot=10.0.0.1:/var/lib/nfsboot,v4,tcp > > > [ 0.000000] Dentry cache hash table entries: 131072 (order: 7, > > > 524288 bytes, linear) > > > [ 0.000000] Inode-cache hash table entries: 65536 (order: 6, > > > 262144 > > > bytes, linear) > > > [ 0.000000] mem auto-init: stack:off, heap alloc:off, heap > > > free:off > > > [ 0.000000] Memory: 945728K/1048576K available (13312K kernel > > > code, > > > 1910K rwdata, 4228K rodata, 1024K init, 6621K bss, 37312K reserved, > > > 65536K cma-reserved, 196608K highmem) > > > [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=2, > > > Nodes=1 > > > [ 0.000000] trace event string verifier disabled > > > [ 0.000000] Running RCU self tests > > > [ 0.000000] rcu: Hierarchical RCU implementation. > > > [ 0.000000] rcu: RCU event tracing is enabled. > > > [ 0.000000] rcu: RCU lockdep checking is enabled. > > > [ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=4 to > > > nr_cpu_ids=2. > > > [ 0.000000] rcu: RCU calculated value of scheduler-enlistment > > > delay > > > is 10 jiffies. > > > [ 0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, > > > nr_cpu_ids=2 > > > [ 0.000000] NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16 > > > [ 0.000000] L2C-310 erratum 769419 enabled > > > [ 0.000000] L2C-310 enabling early BRESP for Cortex-A9 > > > [ 0.000000] L2C-310 full line of zeros enabled for Cortex-A9 > > > [ 0.000000] L2C-310 ID prefetch enabled, offset 16 lines > > > [ 0.000000] L2C-310 dynamic clock gating enabled, standby mode > > > enabled > > > [ 0.000000] L2C-310 cache controller enabled, 16 ways, 512 kB > > > [ 0.000000] L2C-310: CACHE_ID 0x410000c8, AUX_CTRL 0x76450001 > > > [ 0.000000] random: get_random_bytes called from > > > start_kernel+0x364/0x58c with crng_init=0 > > > [ 0.000000] Switching to timer-based delay loop, resolution > > > 333ns > > > [ 0.000001] sched_clock: 32 bits at 3000kHz, resolution 333ns, > > > wraps > > > every 715827882841ns > > > [ 0.000033] clocksource: mxc_timer1: mask: 0xffffffff > > > max_cycles: > > > 0xffffffff, max_idle_ns: 637086815595 ns > > > [ 0.001600] Console: colour dummy device 80x30 > > > [ 0.001663] Lock dependency validator: Copyright (c) 2006 Red > > > Hat, > > > Inc., Ingo Molnar > > > [ 0.001685] ... MAX_LOCKDEP_SUBCLASSES: 8 > > > [ 0.001703] ... MAX_LOCK_DEPTH: 48 > > > [ 0.001721] ... MAX_LOCKDEP_KEYS: 8192 > > > [ 0.001742] ... CLASSHASH_SIZE: 4096 > > > [ 0.001760] ... MAX_LOCKDEP_ENTRIES: 32768 > > > [ 0.001777] ... MAX_LOCKDEP_CHAINS: 65536 > > > [ 0.001795] ... CHAINHASH_SIZE: 32768 > > > [ 0.001812] memory used by lock dependency info: 4061 kB > > > [ 0.001831] memory used for stack traces: 2112 kB > > > [ 0.001849] per task-struct memory footprint: 1536 bytes > > > [ 0.001979] Calibrating delay loop (skipped), value calculated > > > using > > > timer frequency.. 6.00 BogoMIPS (lpj=30000) > > > [ 0.002020] pid_max: default: 32768 minimum: 301 > > > [ 0.002324] Mount-cache hash table entries: 2048 (order: 1, 8192 > > > bytes, linear) > > > [ 0.002375] Mountpoint-cache hash table entries: 2048 (order: 1, > > > 8192 bytes, linear) > > > [ 0.006205] CPU: Testing write buffer coherency: ok > > > [ 0.006386] CPU0: Spectre v2: using BPIALL workaround > > > [ 0.007450] CPU0: thread -1, cpu 0, socket 0, mpidr 80000000 > > > [ 0.010927] Setting up static identity map for 0x10100000 - > > > 0x10100078 > > > [ 0.011749] rcu: Hierarchical SRCU implementation. > > > [ 0.013800] smp: Bringing up secondary CPUs ... > > > [ 0.017275] CPU1: thread -1, cpu 1, socket 0, mpidr 80000001 > > > [ 0.017300] CPU1: Spectre v2: using BPIALL workaround > > > [ 0.018621] smp: Brought up 1 node, 2 CPUs > > > [ 0.018660] SMP: Total of 2 processors activated (12.00 > > > BogoMIPS). > > > [ 0.018691] CPU: All CPU(s) started in SVC mode. > > > [ 0.022001] devtmpfs: initialized > > > [ 0.061678] VFP support v0.3: implementor 41 architecture 3 part > > > 30 > > > variant 9 rev 4 > > > [ 0.064662] clocksource: jiffies: mask: 0xffffffff max_cycles: > > > 0xffffffff, max_idle_ns: 19112604462750000 ns > > > [ 0.064755] futex hash table entries: 512 (order: 3, 32768 > > > bytes, > > > linear) > > > [ 0.068750] pinctrl core: initialized pinctrl subsystem > > > [ 0.075244] NET: Registered protocol family 16 > > > [ 0.102637] DMA: preallocated 256 KiB pool for atomic coherent > > > allocations > > > [ 0.108783] thermal_sys: Registered thermal governor 'step_wise' > > > [ 0.109361] cpuidle: using governor menu > > > [ 0.109609] NET: Registered protocol family 42 > > > [ 0.110336] CPU identified as i.MX6DL, silicon rev 1.3 > > > [ 0.157666] vdd1p1: supplied by regulator-dummy > > > [ 0.160738] vdd3p0: supplied by regulator-dummy > > > [ 0.163009] vdd2p5: supplied by regulator-dummy > > > [ 0.166539] vddpu: supplied by regulator-dummy > > > [ 0.204081] platform 2400000.ipu: Fixing up cyclic dependency > > > with > > > 20e0000.iomuxc-gpr:ipu1_csi1_mux > > > [ 0.204560] platform 2400000.ipu: Fixing up cyclic dependency > > > with > > > 20e0000.iomuxc-gpr:ipu1_csi0_mux > > > [ 0.216152] No ATAGs? > > > [ 0.216575] hw-breakpoint: found 5 (+1 reserved) breakpoint and > > > 1 > > > watchpoint registers. > > > [ 0.216689] hw-breakpoint: maximum watchpoint size is 4 bytes. > > > [ 0.218287] debugfs: Directory 'dummy-iomuxc-gpr@20e0000' with > > > parent 'regmap' already present! > > > [ 0.219892] imx6dl-pinctrl 20e0000.pinctrl: initialized IMX > > > pinctrl > > > driver > > > [ 0.336589] mxs-dma 110000.dma-apbh: initialized > > > [ 0.366282] vgaarb: loaded > > > [ 0.368879] SCSI subsystem initialized > > > [ 0.369795] libata version 3.00 loaded. > > > [ 0.371044] usbcore: registered new interface driver usbfs > > > [ 0.371350] usbcore: registered new interface driver hub > > > [ 0.371534] usbcore: registered new device driver usb > > > [ 0.372134] usb_phy_generic usbphynop1: supply vcc not found, > > > using > > > dummy regulator > > > [ 0.373424] usb_phy_generic usbphynop2: supply vcc not found, > > > using > > > dummy regulator > > > [ 0.380083] i2c i2c-1: IMX I2C adapter registered > > > [ 0.381434] pps_core: LinuxPPS API ver. 1 registered > > > [ 0.381470] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 > > > Rodolfo Giometti <giometti@xxxxxxxx> > > > [ 0.381551] PTP clock support registered > > > [ 0.386332] Bluetooth: Core ver 2.22 > > > [ 0.386506] NET: Registered protocol family 31 > > > [ 0.386535] Bluetooth: HCI device and connection manager > > > initialized > > > [ 0.386695] Bluetooth: HCI socket layer initialized > > > [ 0.386748] Bluetooth: L2CAP socket layer initialized > > > [ 0.386945] Bluetooth: SCO socket layer initialized > > > [ 0.391017] clocksource: Switched to clocksource mxc_timer1 > > > [ 0.763351] VFS: Disk quotas dquot_6.6.0 > > > [ 0.763583] VFS: Dquot-cache hash table entries: 1024 (order 0, > > > 4096 > > > bytes) > > > [ 0.800699] NET: Registered protocol family 2 > > > [ 0.801465] IP idents hash table entries: 16384 (order: 5, > > > 131072 > > > bytes, linear) > > > [ 0.805081] tcp_listen_portaddr_hash hash table entries: 512 > > > (order: > > > 2, 22528 bytes, linear) > > > [ 0.805228] TCP established hash table entries: 8192 (order: 3, > > > 32768 bytes, linear) > > > [ 0.805411] TCP bind hash table entries: 8192 (order: 6, 327680 > > > bytes, linear) > > > [ 0.806559] TCP: Hash tables configured (established 8192 bind > > > 8192) > > > [ 0.807250] UDP hash table entries: 512 (order: 3, 49152 bytes, > > > linear) > > > [ 0.807475] UDP-Lite hash table entries: 512 (order: 3, 49152 > > > bytes, > > > linear) > > > [ 0.808140] NET: Registered protocol family 1 > > > [ 0.811976] RPC: Registered named UNIX socket transport module. > > > [ 0.812100] RPC: Registered udp transport module. > > > [ 0.812129] RPC: Registered tcp transport module. > > > [ 0.812155] RPC: Registered tcp NFSv4.1 backchannel transport > > > module. > > > [ 0.814412] PCI: CLS 0 bytes, default 64 > > > [ 0.815722] armv7-pmu pmu: hw perfevents: no interrupt-affinity > > > property, guessing. > > > [ 1.395389] hw perfevents: enabled with armv7_cortex_a9 PMU > > > driver, > > > 7 counters available > > > [ 1.401550] Initialise system trusted keyrings > > > [ 1.402567] workingset: timestamp_bits=30 max_order=18 > > > bucket_order=0 > > > [ 1.431576] NFS: Registering the id_resolver key type > > > [ 1.431773] Key type id_resolver registered > > > [ 1.431892] Key type id_legacy registered > > > [ 1.432131] jffs2: version 2.2. (NAND) © 2001-2006 Red Hat, Inc. > > > [ 1.434360] fuse: init (API version 7.34) > > > [ 1.538869] Key type asymmetric registered > > > [ 1.539043] Asymmetric key parser 'x509' registered > > > [ 1.539425] bounce: pool size: 64 pages > > > [ 1.539666] io scheduler mq-deadline registered > > > [ 1.539706] io scheduler kyber registered > > > [ 1.546350] imx6q-pcie 1ffc000.pcie: host bridge > > > /soc/pcie@1ffc000 > > > ranges: > > > [ 1.546683] imx6q-pcie 1ffc000.pcie: IO > > > 0x0001f80000..0x0001f8ffff -> 0x0000000000 > > > [ 1.546998] imx6q-pcie 1ffc000.pcie: MEM > > > 0x0001000000..0x0001efffff -> 0x0001000000 > > > [ 1.561233] imx-sdma 20ec000.sdma: Direct firmware load for > > > imx/sdma/sdma-imx6q.bin failed with error -2 > > > [ 1.561380] imx-sdma 20ec000.sdma: Falling back to sysfs > > > fallback > > > for: imx/sdma/sdma-imx6q.bin > > > [ 1.576583] pfuze100-regulator 1-0008: Full layer: 2, Metal > > > layer: > > > 1 > > > [ 1.577276] pfuze100-regulator 1-0008: FAB: 0, FIN: 0 > > > [ 1.577316] pfuze100-regulator 1-0008: pfuze100 found. > > > [ 1.608012] 21f0000.serial: ttymxc3 at MMIO 0x21f0000 (irq = 72, > > > base_baud = 5000000) is a IMX > > > [ 1.662256] imx6q-pcie 1ffc000.pcie: iATU unroll: disabled > > > [ 1.662287] imx6q-pcie 1ffc000.pcie: Detected iATU regions: 4 > > > outbound, 4 inbound > > > [ 1.962914] imx6q-pcie 1ffc000.pcie: Link up > > > [ 2.061645] imx6q-pcie 1ffc000.pcie: Link up > > > [ 2.061667] imx6q-pcie 1ffc000.pcie: Link up, Gen2 > > > [ 2.061687] imx6q-pcie 1ffc000.pcie: Link up > > > [ 2.062985] imx6q-pcie 1ffc000.pcie: PCI host bridge to bus > > > 0000:00 > > > [ 2.063019] pci_bus 0000:00: root bus resource [bus 00-ff] > > > [ 2.063044] pci_bus 0000:00: root bus resource [io 0x0000- > > > 0xffff] > > > [ 2.063067] pci_bus 0000:00: root bus resource [mem 0x01000000- > > > 0x01efffff] > > > [ 2.063496] pci 0000:00:00.0: [16c3:abcd] type 01 class 0x060400 > > > [ 2.063572] pci 0000:00:00.0: reg 0x10: [mem 0x00000000- > > > 0x000fffff] > > > [ 2.063637] pci 0000:00:00.0: reg 0x38: [mem 0x00000000- > > > 0x0000ffff > > > pref] > > > [ 2.063745] pci 0000:00:00.0: Limiting cfg_size to 512 > > > [ 2.064120] pci 0000:00:00.0: supports D1 > > > [ 2.064138] pci 0000:00:00.0: PME# supported from D0 D1 D3hot > > > D3cold > > > [ 2.068753] PCI: bus0: Fast back to back transfers disabled > > > [ 2.069419] pci 0000:01:00.0: [17cb:0306] type 00 class 0xff0000 > > > [ 2.069550] pci 0000:01:00.0: reg 0x10: [mem 0x00000000- > > > 0x00000fff > > > 64bit] > > > [ 2.069633] pci 0000:01:00.0: reg 0x18: [mem 0x00000000- > > > 0x00000fff > > > 64bit] > > > [ 2.070265] pci 0000:01:00.0: PME# supported from D0 D3hot > > > D3cold > > > [ 2.070437] pci 0000:01:00.0: 4.000 Gb/s available PCIe > > > bandwidth, > > > limited by 5.0 GT/s PCIe x1 link at 0000:00:00.0 (capable of 31.506 > > > Gb/s with 16.0 GT/s PCIe x2 link) > > > [ 2.074462] PCI: bus1: Fast back to back transfers disabled > > > [ 2.076179] printk: console [ttymxc3] enabled > > > [ 2.079173] pci 0000:00:00.0: BAR 0: assigned [mem 0x01000000- > > > 0x010fffff] > > > [ 2.702298] pci 0000:00:00.0: BAR 8: assigned [mem 0x01100000- > > > 0x011fffff] > > > [ 2.709133] pci 0000:00:00.0: BAR 6: assigned [mem 0x01200000- > > > 0x0120ffff pref] > > > [ 2.716589] pci 0000:01:00.0: BAR 0: assigned [mem 0x01100000- > > > 0x01100fff 64bit] > > > [ 2.724097] pci 0000:01:00.0: BAR 2: assigned [mem 0x01101000- > > > 0x01101fff 64bit] > > > [ 2.725446] etnaviv etnaviv: bound 130000.gpu (ops gpu_ops) > > > [ 2.731578] pci 0000:00:00.0: PCI bridge to [bus 01-ff] > > > [ 2.738177] etnaviv etnaviv: bound 134000.gpu (ops gpu_ops) > > > [ 2.742511] pci 0000:00:00.0: bridge window [mem 0x01100000- > > > 0x011fffff] > > > [ 2.748092] etnaviv-gpu 130000.gpu: model: GC880, revision: 5106 > > > [ 2.755855] mhi-pci-generic 0000:01:00.0: MHI PCI device found: > > > qcom-sdx55m > > > [ 2.768315] mhi-pci-generic 0000:01:00.0: BAR 0: assigned [mem > > > 0x01100000-0x01100fff 64bit] > > > [ 2.769015] etnaviv-gpu 134000.gpu: model: GC320, revision: 5007 > > > [ 2.776912] mhi-pci-generic 0000:01:00.0: enabling device (0140 > > > -> > > > 0142) > > > [ 2.786483] [drm] Initialized etnaviv 1.3.0 20151214 for etnaviv > > > on > > > minor 0 > > > [ 2.801751] mhi mhi0: Requested to power ON > > > [ 2.808489] mhi mhi0: Power on setup success > > > [ 2.810346] imx-drm display-subsystem: bound imx-ipuv3-crtc.2 > > > (ops > > > ipu_crtc_ops) > > > [ 2.821931] imx-drm display-subsystem: bound imx-ipuv3-crtc.3 > > > (ops > > > ipu_crtc_ops) > > > [ 2.831489] [drm] Initialized imx-drm 1.0.0 20120507 for > > > display- > > > subsystem on minor 1 > > > [ 2.839891] imx-ipuv3 2400000.ipu: IPUv3H probed > > > [ 2.891577] brd: module loaded > > > [ 2.939853] loop: module loaded > > > [ 2.951691] spi@0 enforce active low on chipselect handle > > > [ 2.957268] spi@1 enforce active low on chipselect handle > > > [ 2.972776] spi@0 enforce active low on chipselect handle > > > [ 2.978398] spi@1 enforce active low on chipselect handle > > > [ 2.994315] libphy: Fixed MDIO Bus: probed > > > [ 3.000604] CAN device driver interface > > > [ 3.010081] pps pps0: new PPS source ptp0 > > > [ 3.028687] libphy: fec_enet_mii_bus: probed > > > [ 3.036072] fec 2188000.ethernet eth0: registered PHC device 0 > > > [ 3.044184] PPP generic driver version 2.4.2 > > > [ 3.049501] PPP BSD Compression module registered > > > [ 3.054353] PPP Deflate Compression module registered > > > [ 3.059991] usbcore: registered new interface driver r8152 > > > [ 3.065701] usbcore: registered new interface driver lan78xx > > > [ 3.071583] usbcore: registered new interface driver cdc_ether > > > [ 3.077562] usbcore: registered new interface driver cdc_eem > > > [ 3.083500] usbcore: registered new interface driver smsc95xx > > > [ 3.089413] usbcore: registered new interface driver net1080 > > > [ 3.095293] usbcore: registered new interface driver cdc_subset > > > [ 3.101424] usbcore: registered new interface driver zaurus > > > [ 3.107144] usbcore: registered new interface driver MOSCHIP > > > usb- > > > ethernet driver > > > [ 3.114840] usbcore: registered new interface driver sierra_net > > > [ 3.121028] usbcore: registered new interface driver cdc_ncm > > > [ 3.126862] usbcore: registered new interface driver qmi_wwan > > > [ 3.132835] usbcore: registered new interface driver cdc_mbim > > > [ 3.138607] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) > > > Driver > > > [ 3.145209] ehci-pci: EHCI PCI platform driver > > > [ 3.149951] usbcore: registered new interface driver cdc_wdm > > > [ 3.155907] usbcore: registered new interface driver usb-storage > > > [ 3.162458] usbcore: registered new interface driver > > > usbserial_generic > > > [ 3.169462] usbserial: USB Serial support registered for generic > > > [ 3.175898] usbcore: registered new interface driver ftdi_sio > > > [ 3.181889] usbserial: USB Serial support registered for FTDI > > > USB > > > Serial Device > > > [ 3.189345] usbcore: registered new interface driver option > > > [ 3.195086] usbserial: USB Serial support registered for GSM > > > modem > > > (1-port) > > > [ 3.202258] usbcore: registered new interface driver qcserial > > > [ 3.208119] usbserial: USB Serial support registered for > > > Qualcomm > > > USB modem > > > [ 3.233880] snvs_rtc 20cc000.snvs:snvs-rtc-lp: registered as > > > rtc0 > > > [ 3.240101] snvs_rtc 20cc000.snvs:snvs-rtc-lp: setting system > > > clock > > > to 1970-01-01T00:00:00 UTC (0) > > > [ 3.249753] i2c /dev entries driver > > > [ 3.268851] sdhci: Secure Digital Host Controller Interface > > > driver > > > [ 3.275192] sdhci: Copyright(c) Pierre Ossman > > > [ 3.279581] sdhci-pltfm: SDHCI platform and OF driver helper > > > [ 3.289992] caam 2100000.crypto: Entropy delay = 3200 > > > [ 3.331171] mmc1: SDHCI controller on 2194000.mmc [2194000.mmc] > > > using ADMA > > > [ 3.338991] mmc2: SDHCI controller on 2198000.mmc [2198000.mmc] > > > using ADMA > > > [ 3.356018] caam 2100000.crypto: Instantiated RNG4 SH0 > > > [ 3.416778] caam 2100000.crypto: Instantiated RNG4 SH1 > > > [ 3.422116] caam 2100000.crypto: device ID = 0x0a16010000000100 > > > (Era > > > 4) > > > [ 3.428768] caam 2100000.crypto: job rings = 2, qi = 0 > > > [ 3.453774] mmc3: SDHCI controller on 219c000.mmc [219c000.mmc] > > > using ADMA > > > [ 3.462624] mmc2: new DDR MMC card at address 0001 > > > [ 3.473278] mmcblk2: mmc2:0001 00016G 14.6 GiB > > > [ 3.480232] mmcblk2boot0: mmc2:0001 00016G 4.00 MiB > > > [ 3.481917] caam algorithms registered in /proc/crypto > > > [ 3.487898] mmcblk2boot1: mmc2:0001 00016G 4.00 MiB > > > [ 3.498687] caam 2100000.crypto: registering rng-caam > > > [ 3.499061] mmcblk2rpmb: mmc2:0001 00016G 4.00 MiB, chardev > > > (244:0) > > > [ 3.524714] usbcore: registered new interface driver usbhid > > > [ 3.530329] usbhid: USB HID core driver > > > [ 3.543229] Initializing XFRM netlink socket > > > [ 3.549810] NET: Registered protocol family 10 > > > [ 3.551444] mmc3: new DDR MMC card at address 0001 > > > [ 3.563454] Segment Routing with IPv6 > > > [ 3.568381] sit: IPv6, IPv4 and MPLS over IPv4 tunneling driver > > > [ 3.572261] mmcblk3: mmc3:0001 E0004G 3.64 GiB > > > [ 3.577406] NET: Registered protocol family 17 > > > [ 3.579848] mmcblk3boot0: mmc3:0001 E0004G 4.00 MiB > > > [ 3.583595] NET: Registered protocol family 15 > > > [ 3.589477] mmcblk3boot1: mmc3:0001 E0004G 4.00 MiB > > > [ 3.593057] can: controller area network core > > > [ 3.593470] NET: Registered protocol family 29 > > > [ 3.603122] mmcblk3rpmb: mmc3:0001 E0004G 4.00 MiB, chardev > > > (244:1) > > > [ 3.607179] can: raw protocol > > > [ 3.617067] can: broadcast manager protocol > > > [ 3.621569] can: netlink gateway - max_hops=1 > > > [ 3.624307] mmcblk3: p1 p2 > > > [ 3.626619] Key type dns_resolver registered > > > [ 3.633579] random: fast init done > > > [ 3.643820] Registering SWP/SWPB emulation handler > > > [ 3.649438] Loading compiled-in X.509 certificates > > > [ 3.748476] random: crng init done > > > [ 3.821484] vddarm: supplied by SW1AB > > > [ 3.828699] vddsoc: supplied by SW1C > > > [ 4.431354] mhi mhi0: Wait for device to enter SBL or Mission > > > mode > > > [ 4.453212] mxs_phy 20c9000.usbphy: Data pin can't make good > > > contact. > > > [ 4.469544] ci_hdrc ci_hdrc.1: EHCI Host Controller > > > [ 4.475134] ci_hdrc ci_hdrc.1: new USB bus registered, assigned > > > bus > > > number 1 > > > [ 4.511146] ci_hdrc ci_hdrc.1: USB 2.0 started, EHCI 1.00 > > > [ 4.518600] usb usb1: New USB device found, idVendor=1d6b, > > > idProduct=0002, bcdDevice= 5.13 > > > [ 4.527211] usb usb1: New USB device strings: Mfr=3, Product=2, > > > SerialNumber=1 > > > [ 4.534557] usb usb1: Product: EHCI Host Controller > > > [ 4.539469] usb usb1: Manufacturer: Linux 5.13.6 ehci_hcd > > > [ 4.544979] usb usb1: SerialNumber: ci_hdrc.1 > > > [ 4.556250] hub 1-0:1.0: USB hub found > > > [ 4.560622] hub 1-0:1.0: 1 port detected > > > [ 4.590745] imx_thermal 20c8000.anatop:tempmon: Industrial CPU > > > temperature grade - max:105C critical:100C passive:95C > > > [ 4.861299] usb 1-1: new high-speed USB device number 2 using > > > ci_hdrc > > > [ 5.064624] usb 1-1: New USB device found, idVendor=04b4, > > > idProduct=bd30, bcdDevice= 1.00 > > > [ 5.073441] usb 1-1: New USB device strings: Mfr=0, Product=0, > > > SerialNumber=0 > > > [ 5.087382] hub 1-1:1.0: USB hub found > > > [ 5.091740] hub 1-1:1.0: 2 ports detected > > > [ 5.511390] usb 1-1.1: new high-speed USB device number 3 using > > > ci_hdrc > > > [ 5.664449] usb 1-1.1: New USB device found, idVendor=04b4, > > > idProduct=bd29, bcdDevice= 0.01 > > > [ 5.673182] usb 1-1.1: New USB device strings: Mfr=1, Product=2, > > > SerialNumber=3 > > > [ 5.680706] usb 1-1.1: Product: Remote Download Wireless Adapter > > > [ 5.687033] usb 1-1.1: Manufacturer: Cypress Semiconductor Corp. > > > [ 5.693268] usb 1-1.1: SerialNumber: 000000000001 > > > [ 5.801394] usb 1-1.2: new high-speed USB device number 4 using > > > ci_hdrc > > > [ 5.955345] usb 1-1.2: New USB device found, idVendor=04b4, > > > idProduct=640c, bcdDevice= 1.12 > > > [ 5.964169] usb 1-1.2: New USB device strings: Mfr=1, Product=2, > > > SerialNumber=3 > > > [ 5.971823] usb 1-1.2: Product: BCM2045A0 > > > [ 5.975900] usb 1-1.2: Manufacturer: Cypress Semiconductor Corp. > > > [ 5.982131] usb 1-1.2: SerialNumber: C0EE408051DF > > > [ 11.355278] mhi-pci-generic 0000:01:00.0: failed to power up MHI > > > controller > > > [ 11.388118] mhi-pci-generic: probe of 0000:01:00.0 failed with > > > error > > > -110 > > > > Did you build MHI as builtin? maybe it's just a timeout issue, would > > you be able to increase the timeout_ms value of the > > mhi_controller_config in pci_generic from 8000ms to something like > > 20000ms, just to be sure, I saw some modems taking a long to boot... > > > > Regards, > > Loic > > As Loic suggested, I would just increase the timeout to 30 or 60 > seconds > to > be sure. > Thanks to both of you, to increase the timeout to 24000ms, in addition to disabling the power management seems to correct the issue. > You could also monitor changes in debugfs which can tell you what the > registers read and get states at an interval of every second if you'd > like. > > watch -n 1 cat /sys/kernel/debug/mhi/mhi0/states > watch -n 1 cat /sys/kernel/debug/mhi/mhi0/regdump > root@target:~# cat /sys/kernel/debug/mhi/mhi0/states PM state: M0 Device: Active MHI state: M0 EE: MISSION MODE wake: false M0: 1 M2: 0 M3: 0 device wake: 0 pending packets: 0 root@target:~# cat /sys/kernel/debug/mhi/mhi0/regdump Host PM state: M0 Device state: M0 EE: MISSION MODE Device EE: MISSION MODE state: M0 MHI_REGLEN: 0x100 MHI_VER: 0x1000000 MHI_CFG: 0x2040080 MHI_CTRL: 0x200 MHI_STATUS: 0x201 MHI_WAKE_DB: 0x0 BHI_EXECENV: 0x2 BHI_STATUS: 0x0 BHI_ERRCODE: 0x0 BHI_ERRDBG1: 0x0 BHI_ERRDBG2: 0x0 BHI_ERRDBG3: 0x0 > You could start this after you load the kernel module to get most out > of > the debug rather than building as Y, just build as M as Loic > suggested. Really, thanks for helping and advising. Best regards, Thomas > > Thanks, > Bhaumik > --- > The Qualcomm Innovation Center, Inc. is a member of the Code Aurora > Forum, > a Linux Foundation Collaborative Project -- Thomas Perrot, Bootlin Embedded Linux and kernel engineering https://bootlin.com
Attachment:
signature.asc
Description: This is a digitally signed message part