[BUG BISECT] Net boot fails on VF50 after "dmaengine: fsl-edma: support little endian for edma driver"

From: Krzysztof KozÅowski
Date: Tue Jul 02 2019 - 08:12:59 EST


Hi,

Bisect pointed commit:
commit 002905eca5bedab08bafd9e325bbbb41670c7712
Author: Peng Ma <peng.ma@xxxxxxx>
Date: Thu Jun 13 10:27:08 2019 +0000
dmaengine: fsl-edma: support little endian for edma driver

as a reason of NFSv4 root boot failures. Toradex Colibri VF50 (Cortex
A5) on Toradex Iris board.

The user-space starts but hangs - a lot of messages are missing or
seriously delayed.

Please revert the patch of fix it. If needed I can provide more
details about test system - let me know.

Full log attached.

Best regards,
Krzysztof
[ 0.000000] Booting Linux on physical CPU 0x0
[ 0.000000] Linux version 5.2.0-rc1-00052-g002905eca5be (krzk@PC-kkoz) (gcc version 5.4.0 20160609 (Ubuntu/Linaro 5.4.0-6ubuntu1~16.04.9)) #731 Tue Jul 2 14:07:36 CEST 2019
[ 0.000000] CPU: ARMv7 Processor [410fc051] revision 1 (ARMv7), cr=10c5387d
[ 0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT aliasing instruction cache
[ 0.000000] OF: fdt: Machine model: Toradex Colibri VF50 on Colibri Evaluation Board
[ 0.000000] Memory policy: Data cache writeback
[ 0.000000] cma: Reserved 16 MiB at 0x87000000
[ 0.000000] CPU: All CPU(s) started in SVC mode.
[ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 32512
[ 0.000000] Kernel command line: ip=:::::eth0: root=/dev/nfs ubi.mtd=ubi1 console=tty1 console=ttyLP0,115200n8 consoleblank=0
[ 0.000000] Dentry cache hash table entries: 16384 (order: 4, 65536 bytes)
[ 0.000000] Inode-cache hash table entries: 8192 (order: 3, 32768 bytes)
[ 0.000000] Memory: 103832K/131072K available (6144K kernel code, 197K rwdata, 1728K rodata, 1024K init, 144K bss, 10856K reserved, 16384K cma-reserved)
[ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
[ 0.000000] NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16
[ 0.000000] random: get_random_bytes called from start_kernel+0x288/0x418 with crng_init=0
[ 0.000056] sched_clock: 64 bits at 132MHz, resolution 7ns, wraps every 2199023255551ns
[ 0.000126] clocksource: arm_global_timer: mask: 0xffffffffffffffff max_cycles: 0x1e7178659b, max_idle_ns: 440795204301 ns
[ 0.000212] Switching to timer-based delay loop, resolution 7ns
[ 0.001307] Console: colour dummy device 80x30
[ 0.001900] printk: console [tty1] enabled
[ 0.001994] Calibrating delay loop (skipped), value calculated using timer frequency.. 264.00 BogoMIPS (lpj=1320000)
[ 0.002085] pid_max: default: 32768 minimum: 301
[ 0.002479] Mount-cache hash table entries: 1024 (order: 0, 4096 bytes)
[ 0.002588] Mountpoint-cache hash table entries: 1024 (order: 0, 4096 bytes)
[ 0.004031] *** VALIDATE proc ***
[ 0.004467] *** VALIDATE cgroup1 ***
[ 0.004549] *** VALIDATE cgroup2 ***
[ 0.004748] CPU: Testing write buffer coherency: ok
[ 0.007201] Setting up static identity map for 0x80100000 - 0x80100060
[ 0.009654] devtmpfs: initialized
[ 0.022643] VFP support v0.3: implementor 41 architecture 2 part 30 variant 5 rev 1
[ 0.023499] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[ 0.023633] futex hash table entries: 256 (order: -1, 3072 bytes)
[ 0.025932] pinctrl core: initialized pinctrl subsystem
[ 0.029072] NET: Registered protocol family 16
[ 0.033335] DMA: preallocated 256 KiB pool for atomic coherent allocations
[ 0.036355] cpuidle: using governor menu
[ 0.036762] hw-breakpoint: found 2 (+1 reserved) breakpoint and 1 watchpoint registers.
[ 0.036843] hw-breakpoint: maximum watchpoint size is 4 bytes.
[ 0.048865] vf610-pinctrl 40048000.iomuxc: initialized IMX pinctrl driver
[ 0.144412] +V3.3: supplied by 3.3V
[ 0.146779] SCSI subsystem initialized
[ 0.147578] usbcore: registered new interface driver usbfs
[ 0.147822] usbcore: registered new interface driver hub
[ 0.148167] usbcore: registered new device driver usb
[ 0.150969] i2c i2c-0: using dma0chan0 (tx) and dma0chan1 (rx) for DMA transfers
[ 0.151079] i2c i2c-0: IMX I2C adapter registered
[ 0.151753] pps_core: LinuxPPS API ver. 1 registered
[ 0.151823] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@xxxxxxxx>
[ 0.151973] PTP clock support registered
[ 0.155752] clocksource: Switched to clocksource arm_global_timer
[ 0.193726] NET: Registered protocol family 2
[ 0.195459] tcp_listen_portaddr_hash hash table entries: 512 (order: 0, 4096 bytes)
[ 0.195624] TCP established hash table entries: 1024 (order: 0, 4096 bytes)
[ 0.195721] TCP bind hash table entries: 1024 (order: 0, 4096 bytes)
[ 0.195948] TCP: Hash tables configured (established 1024 bind 1024)
[ 0.196517] UDP hash table entries: 256 (order: 0, 4096 bytes)
[ 0.196649] UDP-Lite hash table entries: 256 (order: 0, 4096 bytes)
[ 0.197279] NET: Registered protocol family 1
[ 0.199112] RPC: Registered named UNIX socket transport module.
[ 0.199210] RPC: Registered udp transport module.
[ 0.199253] RPC: Registered tcp transport module.
[ 0.199291] RPC: Registered tcp NFSv4.1 backchannel transport module.
[ 0.201363] hw perfevents: enabled with armv7_cortex_a5 PMU driver, 3 counters available
[ 0.204878] Initialise system trusted keyrings
[ 0.205567] workingset: timestamp_bits=30 max_order=15 bucket_order=0
[ 0.224600] NFS: Registering the id_resolver key type
[ 0.224753] Key type id_resolver registered
[ 0.224802] Key type id_legacy registered
[ 0.224976] ntfs: driver 2.1.32 [Flags: R/W].
[ 0.226803] fuse: init (API version 7.30)
[ 0.228826] Key type asymmetric registered
[ 0.228917] Asymmetric key parser 'x509' registered
[ 0.229004] io scheduler mq-deadline registered
[ 0.229056] io scheduler kyber registered
[ 0.243446] 40027000.serial: ttyLP0 at MMIO 0x40027000 (irq = 19, base_baud = 4125000) is a FSL_LPUART
[ 0.718642] printk: console [ttyLP0] enabled
[ 0.724672] 40028000.serial: ttyLP1 at MMIO 0x40028000 (irq = 20, base_baud = 4125000) is a FSL_LPUART
[ 0.736152] 40029000.serial: ttyLP2 at MMIO 0x40029000 (irq = 21, base_baud = 4125000) is a FSL_LPUART
[ 0.750981] brd: module loaded
[ 0.776021] loop: module loaded
[ 0.782734] nand: device found, Manufacturer ID: 0xc2, Chip ID: 0xf1
[ 0.789288] nand: Macronix NAND 128MiB 3,3V 8-bit
[ 0.794058] nand: 128 MiB, SLC, erase size: 128 KiB, page size: 2048, OOB size: 64
[ 0.802176] Bad block table found at page 65472, version 0x01
[ 0.808308] Bad block table found at page 65408, version 0x01
[ 0.814355] nand_read_bbt: bad block at 0x0000013c0000
[ 0.819832] 6 fixed-partitions partitions found on MTD device vf610_nfc
[ 0.826597] Creating 6 MTD partitions on "vf610_nfc":
[ 0.831722] 0x000000000000-0x000000020000 : "vf-bcb"
[ 0.838413] 0x000000020000-0x000000180000 : "u-boot"
[ 0.844988] 0x000000180000-0x0000001c0000 : "u-boot-env"
[ 0.852132] 0x0000001c0000-0x000004080000 : "ubi1"
[ 0.859177] 0x000004080000-0x000007f40000 : "ubi2"
[ 0.866141] 0x000007f40000-0x000007f80000 : "reserved"
[ 0.877849] libphy: Fixed MDIO Bus: probed
[ 0.895255] libphy: fec_enet_mii_bus: probed
[ 0.901726] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[ 0.909279] usbcore: registered new interface driver usb-storage
[ 0.915720] usbcore: registered new interface driver usbserial_generic
[ 0.922589] usbserial: USB Serial support registered for generic
[ 0.928892] usbcore: registered new interface driver ftdi_sio
[ 0.934818] usbserial: USB Serial support registered for FTDI USB Serial Device
[ 0.942435] usbcore: registered new interface driver pl2303
[ 0.948290] usbserial: USB Serial support registered for pl2303
[ 0.967265] snvs_rtc 400a7000.snvs:snvs-rtc-lp: registered as rtc0
[ 0.973873] i2c /dev entries driver
[ 0.982362] imx2-wdt 4003e000.wdog: timeout 60 sec (nowayout=0)
[ 0.989821] sdhci: Secure Digital Host Controller Interface driver
[ 0.996188] sdhci: Copyright(c) Pierre Ossman
[ 1.000597] sdhci-pltfm: SDHCI platform and OF driver helper
[ 1.007851] sdhci-esdhc-imx 400b2000.esdhc: Got CD GPIO
[ 1.040860] mmc0: SDHCI controller on 400b2000.esdhc [400b2000.esdhc] using ADMA
[ 1.060981] NET: Registered protocol family 17
[ 1.066026] Key type dns_resolver registered
[ 1.070612] Registering SWP/SWPB emulation handler
[ 1.077587] registered taskstats version 1
[ 1.081760] Loading compiled-in X.509 certificates
[ 1.090291] regulator-usbh-vbus GPIO handle specifies active low - ignored
[ 1.097661] VCC_USB[1-4]: supplied by 5V
[ 1.107410] ci_hdrc ci_hdrc.1: EHCI Host Controller
[ 1.112492] ci_hdrc ci_hdrc.1: new USB bus registered, assigned bus number 1
[ 1.145914] ci_hdrc ci_hdrc.1: USB 2.0 started, EHCI 1.00
[ 1.153885] hub 1-0:1.0: USB hub found
[ 1.157998] hub 1-0:1.0: 1 port detected
[ 1.165981] ubi0: default fastmap pool size: 25
[ 1.170601] ubi0: default fastmap WL pool size: 12
[ 1.175431] ubi0: attaching mtd3
[ 1.205997] random: fast init done
[ 1.258665] ubi0: attached by fastmap
[ 1.262407] ubi0: fastmap pool size: 25
[ 1.266421] ubi0: fastmap WL pool size: 12
[ 1.281459] ubi0: attached mtd3 (name "ubi1", size 62 MiB)
[ 1.287166] ubi0: PEB size: 131072 bytes (128 KiB), LEB size: 126976 bytes
[ 1.294095] ubi0: min./max. I/O unit sizes: 2048/2048, sub-page size 2048
[ 1.301003] ubi0: VID header offset: 2048 (aligned 2048), data offset: 4096
[ 1.308080] ubi0: good PEBs: 501, bad PEBs: 1, corrupted PEBs: 0
[ 1.314133] ubi0: user volume: 5, internal volumes: 1, max. volumes count: 128
[ 1.321470] ubi0: max/mean erase counter: 2/1, WL threshold: 4096, image sequence number: 0
[ 1.329943] ubi0: available PEBs: 0, total reserved PEBs: 501, PEBs reserved for bad PEB handling: 19
[ 1.339326] ubi0: background thread "ubi_bgt0d" started, PID 77
[ 1.346120] snvs_rtc 400a7000.snvs:snvs-rtc-lp: setting system clock to 1970-01-01T00:00:00 UTC (0)
[ 1.361214] Micrel KSZ8041 400d1000.ethernet-1:00: attached PHY driver [Micrel KSZ8041] (mii_bus:phy_addr=400d1000.ethernet-1:00, irq=POLL)
[ 1.374935] fec 400d1000.ethernet eth0: Link is Up - 100Mbps/Full - flow control off
[ 1.405878] Sending DHCP requests ., OK
[ 1.469786] IP-Config: Got DHCP answer from 192.168.10.1, my address is 192.168.10.17
[ 1.477763] IP-Config: Complete:
[ 1.481062] device=eth0, hwaddr=00:14:2d:2c:a1:2e, ipaddr=192.168.10.17, mask=255.255.255.0, gw=192.168.10.1
[ 1.491443] host=192.168.10.17, domain=, nis-domain=(none)
[ 1.497465] bootserver=192.168.10.1, rootserver=192.168.10.1, rootpath=/srv/nfs/colibri_vf,v4,tcp
[ 1.497483] nameserver0=192.168.10.1
[ 1.678362] VFS: Mounted root (nfs4 filesystem) on device 0:13.
[ 1.686077] usb 1-1: new high-speed USB device number 2 using ci_hdrc
[ 1.692969] devtmpfs: mounted
[ 1.704559] Freeing unused kernel memory: 1024K
[ 1.709848] Run /sbin/init as init process
[ 2.879008] systemd[1]: System time before build time, advancing clock.
[ 3.068391] random: systemd: uninitialized urandom read (16 bytes read)
[ 3.119319] systemd[1]: systemd 232 running in system mode. (-PAM -AUDIT -SELINUX -IMA -APPARMOR -SMACK +SYSVINIT +UTMP -LIBCRYPTSETUP -GCRYPT -GNUTLS +ACL +XZ -LZ4 -SECCOMP +BLKID -ELFUTILS +KMOD -IDN)
[ 3.139859] systemd[1]: Detected architecture arm.
[ 33.774655] systemd[1]: Set hostname to <col-vf50-proceq>.
[ 33.951009] random: systemd: uninitialized urandom read (16 bytes read)
[ 34.397842] random: systemd-sysv-ge: uninitialized urandom read (16 bytes read)
[ 34.461872] systemd-fstab-generator[96]: Checking was requested for "ubi0:config", but it is not a device.
[ 64.512904] random: systemd: uninitialized urandom read (16 bytes read)
[ 64.565275] random: systemd: uninitialized urandom read (16 bytes read)
[ 64.573224] random: systemd: uninitialized urandom read (16 bytes read)
[ 65.717719] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.
[ 95.851417] systemd[1]: Listening on Journal Socket.