AnsweredAssumed Answered

iMX8M dual processor EHCI driver issue

Question asked by Jared Kung on Mar 25, 2019
Latest reply on May 3, 2019 by igorpadykov

Hi, 

 

We encountered an issue about “rcu_preempt detected stalls on CPUs / tasks”. The related logs are below. Please help to see the problem. Thank You!

 

We hang-up with EHCI driver in kernel.

 

**********************************

Processor: i.MX8M dual core

Memory: 1GB DDR3L

**********************************

 

----------------------------------------------------------------------------------

Normal Boot
Hit any key to stop autoboot: 0
switch to partitions #0, OK
mmc1 is current device
reading boot.scr
** Unable to read file boot.scr **
reading Image
19612160 bytes read in 846 ms (22.1 MiB/s)
Booting from mmc ...
reading xxxx-xxxx-imx8m-1gb-ddr3l.dtb
38761 bytes read in 20 ms (1.8 MiB/s)
## Flattened Device Tree blob at 43000000
Booting using the fdt blob at 0x43000000
Using Device Tree in place at 0000000043000000, end 000000004300c768

Starting kernel ...

[ 0.000000] Booting Linux on physical CPU 0x0
[ 0.000000] Linux version 4.9.88_DVT_V1.04 (build@ubuntu) (gcc version 6.2.0 (GCC) ) #1 SMP PREEMPT Sat Feb 23 17:18:48 CST 2019
[ 0.000000] Boot CPU: AArch64 Processor [410fd034]
[ 0.000000] earlycon: ec_imx6q0 at MMIO 0x0000000030860000 (options '115200')
[ 0.000000] bootconsole [ec_imx6q0] enabled
[ 0.000000] efi: Getting EFI parameters from FDT:
[ 0.000000] efi: UEFI not found.
[ 0.000000] Reserved memory: created CMA memory pool at 0x0000000068000000, size 384 MiB
[ 0.000000] OF: reserved mem: initialized node linux,cma, compatible id shared-dma-pool
[ 0.000000] psci: probing for conduit method from DT.
[ 0.000000] psci: PSCIv1.0 detected in firmware.
[ 0.000000] psci: Using standard PSCI v0.2 function IDs
[ 0.000000] psci: MIGRATE_INFO_TYPE not supported.
[ 0.000000] psci: SMC Calling Convention v1.0
[ 0.000000] percpu: Embedded 21 pages/cpu @ffff800027f9a000 s48536 r8192 d29288 u86016
[ 0.000000] Detected VIPT I-cache on CPU0
[ 0.000000] CPU features: enabling workaround for ARM erratum 845719
[ 0.000000] Built 1 zonelists in Zone order, mobility grouping on. Total pages: 258048
[ 0.000000] Kernel command line: console=ttymxc0,115200 earlycon=ec_imx6q,0x30860000,115200 root=/dev/mmcblk1p2 rootwait rw
[ 0.000000] PID hash table entries: 4096 (order: 3, 32768 bytes)
[ 0.000000] Dentry cache hash table entries: 131072 (order: 8, 1048576 bytes)
[ 0.000000] Inode-cache hash table entries: 65536 (order: 7, 524288 bytes)
[ 0.000000] Memory: 617416K/1048576K available (11644K kernel code, 1296K rwdata, 5068K rodata, 1088K init, 369K bss, 37944K reserved, 393216K cma-reserved)
[ 0.000000] Virtual kernel memory layout:
[ 0.000000] modules : 0xffff000000000000 - 0xffff000008000000 ( 128 MB)
[ 0.000000] vmalloc : 0xffff000008000000 - 0xffff7dffbfff0000 (129022 GB)
[ 0.000000] .text : 0xffff000008080000 - 0xffff000008be0000 ( 11648 KB)
[ 0.000000] .rodata : 0xffff000008be0000 - 0xffff0000090e0000 ( 5120 KB)
[ 0.000000] .init : 0xffff0000090e0000 - 0xffff0000091f0000 ( 1088 KB)
[ 0.000000] .data : 0xffff0000091f0000 - 0xffff000009334200 ( 1297 KB)
[ 0.000000] .bss : 0xffff000009334200 - 0xffff00000939078c ( 370 KB)
[ 0.000000] fixed : 0xffff7dfffe7fb000 - 0xffff7dfffec00000 ( 4116 KB)
[ 0.000000] PCI I/O : 0xffff7dfffee00000 - 0xffff7dffffe00000 ( 16 MB)
[ 0.000000] vmemmap : 0xffff7e0000000000 - 0xffff800000000000 ( 2048 GB maximum)
[ 0.000000] 0xffff7e0000000000 - 0xffff7e0001000000 ( 16 MB actual)
[ 0.000000] memory : 0xffff800000000000 - 0xffff800040000000 ( 1024 MB)
[ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=2, Nodes=1
[ 0.000000] Preemptible hierarchical RCU implementation.
[ 0.000000] Build-time adjustment of leaf fanout to 64.
[ 0.000000] RCU restricting CPUs from NR_CPUS=64 to nr_cpu_ids=2.
[ 0.000000] RCU: Adjusting geometry for rcu_fanout_leaf=64, nr_cpu_ids=2
[ 0.000000] NR_IRQS:64 nr_irqs:64 0
[ 0.000000] GICv3: GIC: Using split EOI/Deactivate mode
[ 0.000000] ITS: No ITS available, not enabling LPIs
[ 0.000000] GICv3: CPU0: found redistributor 0 region 0:0x0000000038880000
[ 0.000000] i.MX8MQ clock driver init done
[ 0.000000] arm_arch_timer: Architected cp15 timer(s) running at 8.33MHz (phys).
[ 0.000000] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0x1ec0311ec, max_idle_ns: 440795202152 ns
[ 0.000004] sched_clock: 56 bits at 8MHz, resolution 120ns, wraps every 2199023255541ns
[ 0.008297] system counter timer init
[ 0.011726] sched_clock: 56 bits at 8MHz, resolution 120ns, wraps every 2199023255541ns
[ 0.019709] clocksource: imx sysctr: mask: 0xffffffffffffff max_cycles: 0x1ec0311ec, max_idle_ns: 440795202152 ns
[ 0.030393] Console: colour dummy device 80x25
[ 0.034467] Calibrating delay loop (skipped), value calculated using timer frequency.. 16.66 BogoMIPS (lpj=33333)
[ 0.044734] pid_max: default: 32768 minimum: 301
[ 0.049421] Security Framework initialized
[ 0.053498] Mount-cache hash table entries: 2048 (order: 2, 16384 bytes)
[ 0.060179] Mountpoint-cache hash table entries: 2048 (order: 2, 16384 bytes)
[ 0.068067] ASID allocator initialised with 32768 entries
[ 0.105942] Cannot find MU entry in device tree
[ 0.107747] CPU identified as i.MX8MQ, silicon rev 2.0
[ 0.112886] EFI services will not be available.
[ 0.165531] Detected VIPT I-cache on CPU1
[ 0.165559] GICv3: CPU1: found redistributor 1 region 0:0x00000000388a0000
[ 0.165593] CPU1: Booted secondary processor [410fd034]
[ 0.165817] Brought up 2 CPUs
[ 0.182053] SMP: Total of 2 processors activated.
[ 0.186771] CPU features: detected feature: GIC system register CPU interface
[ 0.193923] CPU features: detected feature: 32-bit EL0 Support
[ 0.200088] CPU features: detected feature: Kernel page table isolation (KPTI)
[ 0.220765] CPU: All CPU(s) started at EL2
[ 0.222062] alternatives: patching kernel code
[ 0.227558] devtmpfs: initialized
[ 0.237165] DMI not present or invalid.
[ 0.238488] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns
[ 0.247928] futex hash table entries: 512 (order: 4, 65536 bytes)
[ 0.265212] pinctrl core: initialized pinctrl subsystem
[ 0.269257] NET: Registered protocol family 16
[ 0.288160] cpuidle: using governor menu
[ 0.289896] vdso: 2 pages (1 code @ ffff000008be7000, 1 data @ ffff0000091f4000)
[ 0.296660] hw-breakpoint: found 6 breakpoint and 4 watchpoint registers.
[ 0.307818] DMA: preallocated 256 KiB pool for atomic allocations
[ 0.311832] Serial: AMBA PL011 UART driver
[ 0.324148] imx8mq-pinctrl 30330000.iomuxc: Invalid fsl,pins property in node /iomuxc@30330000/lec-imx8m/pcie0grp
[ 0.331766] imx8mq-pinctrl 30330000.iomuxc: initialized IMX pinctrl driver
[ 0.395080] HugeTLB registered 2 MB page size, pre-allocated 0 pages
[ 0.411262] ACPI: Interpreter disabled.
[ 0.415130] mxs-dma 33000000.dma-apbh: initialized
[ 0.419023] vgaarb: loaded
[ 0.420231] SCSI subsystem initialized
[ 0.424475] usbcore: registered new interface driver usbfs
[ 0.429339] usbcore: registered new interface driver hub
[ 0.434501] usbcore: registered new device driver usb
[ 0.440478] i2c i2c-0: IMX I2C adapter registered
[ 0.444174] i2c i2c-0: can't use DMA, using PIO instead.
[ 0.449942] i2c i2c-1: IMX I2C adapter registered
[ 0.454199] i2c i2c-1: can't use DMA, using PIO instead.
[ 0.460085] 2-0020 supply vcc not found, using dummy regulator
[ 0.614171] i2c i2c-2: IMX I2C adapter registered
[ 0.616023] i2c i2c-2: can't use DMA, using PIO instead.
[ 0.621828] i2c i2c-3: IMX I2C adapter registered
[ 0.626064] i2c i2c-3: can't use DMA, using PIO instead.
[ 0.631986] media: Linux media interface: v0.10
[ 0.636080] Linux video capture interface: v2.00
[ 0.640652] pps_core: LinuxPPS API ver. 1 registered
[ 0.645560] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>
[ 0.654728] PTP clock support registered
[ 0.658895] dmi: Firmware registration failed.
[ 0.663074] Linux cec interface: v0.10
[ 0.667325] MU is ready for cross core communication!
[ 0.673022] virtio_rpmsg_bus virtio0: rpmsg host is online
[ 0.677458] imx rpmsg driver is registered.
[ 0.681894] Advanced Linux Sound Architecture Driver Initialized.
[ 0.689783] clocksource: Switched to clocksource arch_sys_counter
[ 0.693967] VFS: Disk quotas dquot_6.6.0
[ 0.697679] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
[ 0.704841] pnp: PnP ACPI: disabled
[ 0.719819] NET: Registered protocol family 2
[ 0.721750] TCP established hash table entries: 8192 (order: 4, 65536 bytes)
[ 0.728537] TCP bind hash table entries: 8192 (order: 5, 131072 bytes)
[ 0.735106] TCP: Hash tables configured (established 8192 bind 8192)
[ 0.741401] UDP hash table entries: 512 (order: 2, 16384 bytes)
[ 0.747261] UDP-Lite hash table entries: 512 (order: 2, 16384 bytes)
[ 0.753803] NET: Registered protocol family 1
[ 0.758568] RPC: Registered named UNIX socket transport module.
[ 0.763890] RPC: Registered udp transport module.
[ 0.768649] RPC: Registered tcp transport module.
[ 0.773304] RPC: Registered tcp NFSv4.1 backchannel transport module.
[ 0.780334] hw perfevents: enabled with armv8_pmuv3 PMU driver, 7 counters available
[ 0.788008] kvm [1]: 8-bit VMID
[ 0.790661] kvm [1]: IDMAP page: 40bd2000
[ 0.794724] kvm [1]: HYP VA range: 800000000000:ffffffffffff
[ 0.801204] kvm [1]: Hyp mode initialized successfully
[ 0.805593] kvm [1]: GICv3: no GICV resource entry
[ 0.810277] kvm [1]: disabling GICv2 emulation
[ 0.814892] kvm [1]: GIC system register CPU interface enabled
[ 0.820729] kvm [1]: vgic interrupt IRQ1
[ 0.824558] kvm [1]: virtual timer IRQ4
[ 0.833269] audit: initializing netlink subsys (disabled)
[ 0.835855] audit: type=2000 audit(0.735:1): initialized
[ 0.842203] workingset: timestamp_bits=46 max_order=18 bucket_order=0
[ 0.861634] squashfs: version 4.0 (2009/01/31) Phillip Lougher
[ 0.865855] NFS: Registering the id_resolver key type
[ 0.869689] Key type id_resolver registered
[ 0.873928] Key type id_legacy registered
[ 0.877890] nfs4filelayout_init: NFSv4 File Layout Driver Registering...
[ 0.884672] jffs2: version 2.2. (NAND) ? 2001-2006 Red Hat, Inc.
[ 0.904834] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 244)
[ 0.909406] io scheduler noop registered
[ 0.913442] io scheduler cfq registered (default)
[ 0.920415] libphy: mdio_driver_register: phy-bcm-ns2-pci
[ 0.935166] imx-sdma 30bd0000.sdma: no iram assigned, using external mem
[ 0.940514] imx-sdma 30bd0000.sdma: loaded firmware 4.2
[ 0.948563] imx-sdma 302c0000.sdma: no iram assigned, using external mem
[ 0.953629] imx-sdma 302c0000.sdma: loaded firmware 4.2
[ 0.964573] Bus freq driver module loaded
[ 0.966677] xenfs: not registering filesystem on non-xen platform
[ 0.973584] pfuze100-regulator 0-0008: Full layer: 2, Metal layer: 1
[ 0.978724] pfuze100-regulator 0-0008: FAB: 0, FIN: 0
[ 0.983327] pfuze100-regulator 0-0008: pfuze100 found.
[ 1.008074] Serial: 8250/16550 driver, 4 ports, IRQ sharing disabled
[ 1.014849] SuperH (H)SC?
? driver initialized
[ 1.019549] console [ttymxc0] enabled
[ 1.023302] bootconsole [ec_imx6q0] disabled
[ 1.028199] 30880000.serial: ttymxc2 at MMIO 0x30880000 (irq = 40, base_baud = 1562500) is a IMX
[ 1.037860] 30890000.serial: ttymxc1 at MMIO 0x30890000 (irq = 41, base_baud = 5000000) is a IMX
[ 1.047579] msm_serial: driver initialized
[ 1.058440] [drm] Initialized
[ 1.065465] [drm] Supports vblank timestamp caching Rev 2 (21.10.2013).
[ 1.072103] [drm] No driver support for vblank timestamp query.
[ 1.078211] imx-drm display-subsystem: bound imx-dcss-crtc.0 (ops dcss_crtc_ops)
[ 1.085742] [drm] mode:1920x1080p60, pixel clock 148500 kHz
[ 1.091562] [drm] Pixel clock frequency: 148500 kHz, character clock frequency: 148500, color depth is 8-bit.
[ 1.101492] [drm] VCO frequency is 5940000 kHz
[ 1.130707] [drm] CDN_API_General_Write_Register_blocking LANES_CONFIG ret = 0
[ 1.139406] [drm] hdmi-audio-codec driver bound to HDMI
[ 1.144666] imx-drm display-subsystem: bound 32c00000.hdmi (ops imx_hdp_imx_ops)
[ 1.152438] Raw EDID:
[ 1.154732] 00 00 10 74 00 00 00 00 00 00 00 00 00 00 00 00
[ 1.160548] 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[ 1.166310] 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[ 1.172125] 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[ 1.177886] 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[ 1.183701] 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[ 1.189468] 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[ 1.195230] 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[ 1.201255] Raw EDID:
[ 1.203544] 00 00 10 74 00 00 00 00 00 00 00 00 00 00 00 00
[ 1.209305] 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[ 1.215066] 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[ 1.220827] 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[ 1.226588] 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[ 1.232348] 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[ 1.238109] 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[ 1.243870] 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[ 1.249889] Raw EDID:
[ 1.252168] 00 00 10 74 00 00 00 00 00 00 00 00 00 00 00 00
[ 1.257928] 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[ 1.263688] 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[ 1.269448] 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[ 1.275208] 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[ 1.280967] 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[ 1.286728] 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[ 1.292487] 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[ 1.298508] Raw EDID:
[ 1.300786] 00 00 10 74 00 00 00 00 00 00 00 00 00 00 00 00
[ 1.306545] 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[ 1.312306] 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[ 1.318070] 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[ 1.323832] 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[ 1.329592] 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[ 1.335353] 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[ 1.341113] 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[ 1.346878] imx-drm display-subsystem: HDMI-A-1: EDID block 0 invalid.
[ 1.356074] [drm] mode:1024x768p60, pixel clock 65000 kHz
[ 1.356253] [drm] Pixel clock frequency: 65000 kHz, character clock frequency: 65000, color depth is 8-bit.
[ 1.356266] [drm:phy_cfg_t28hpc] *ERROR* This pixel clock frequency (65000 kHz) is not supported.
[ 1.356272] [drm:hdmi_phy_init_t28hpc] *ERROR* failed to set phy pclock
[ 1.356279] [drm:imx_hdp_bridge_mode_set] *ERROR* Failed to initialise HDP PHY
[ 1.356293] [drm] OPIPE_CFG: gamut = 1, nl = 1, pr = 1, pix_format = 875713089
[ 1.939988] Console: switching to colour frame buffer device 128x48
[ 2.010340] imx-drm display-subsystem: fb0: frame buffer device
[ 2.039356] loop: module loaded
[ 2.043605] hisi_sas: driver version v1.6
[ 2.051082] slram: not enough parameters.
[ 2.056393] spi_imx 30830000.ecspi: dma setup error -19, use pio
[ 2.063000] spi_imx 30830000.ecspi: probed
[ 2.069336] libphy: Fixed MDIO Bus: probed
[ 2.073924] NXP PHY: loading NXP PHY driver: [autonomous mode]
[ 2.080011] tun: Universal TUN/TAP device driver, 1.6
[ 2.085081] tun: (C) 1999-2004 Max Krasnyansky <maxk@qualcomm.com>
[ 2.091713] CAN device driver interface
[ 2.106689] mcp251x spi2.0 can0: MCP2515 successfully initialized.
[ 2.115047] 30be0000.ethernet supply phy not found, using dummy regulator
[ 2.124528] pps pps0: new PPS source ptp0
[ 2.132004] libphy: fec_enet_mii_bus: probed
[ 2.136452] random: fast init done
[ 2.141383] fec 30be0000.ethernet eth0: registered PHC device 0
[ 2.148313] e1000e: Intel(R) PRO/1000 Network Driver - 3.2.6-k
[ 2.154224] e1000e: Copyright(c) 1999 - 2015 Intel Corporation.
[ 2.160327] igb: Intel(R) Gigabit Ethernet Network Driver - version 5.4.0-k
[ 2.167311] igb: Copyright (c) 2007-2014 Intel Corporation.
[ 2.173054] igbvf: Intel(R) Gigabit Virtual Function Network Driver - version 2.4.0-k
[ 2.180900] igbvf: Copyright (c) 2009 - 2012 Intel Corporation.
[ 2.186987] sky2: driver version 1.30
[ 23.193778] INFO: rcu_preempt detected stalls on CPUs/tasks:
[ 23.199470] 1-...: (0 ticks this GP) idle=bbb/140000000000000/0 softirq=288/288 fqs=2625
[ 23.207738] (detected by 0, t=5252 jiffies, g=-184, c=-185, q=119)
[ 23.214028] Task dump for CPU 1:
[ 23.217261] swapper/0 R running task 0 1 0 0x00000002
[ 23.224347] Call trace:
[ 23.226812] [<ffff000008085e48>] __switch_to+0x88/0xb0
[ 23.231957] [<ffff800027fe29a8>] 0xffff800027fe29a8

-----------------------------------------------------------------------------------------------

Outcomes