[BUG BISECT] Missing MTD NAND partitions - mtd: rawnand: Move the ->exec_op() method to nand_controller_ops

From: Krzysztof KozÅowski
Date: Tue Nov 20 2018 - 04:46:50 EST


Hi all,

Since few days linux-next has problem on Freescale VF500 - MTD seems
to be broken.

Bisect pointed me to commit 7c27338c728e39ef47c83d101959aa332506969d
("mtd: rawnand: Move the ->exec_op() method to nand_controller_ops")
as reason of failure to find MTD partitions.

Toradex Colibri VF50 on Iris board (ARMv7, UP, Cortext-A5, NXP VF500,
128 MB RAM, 128 MB NAND, Systemd: v232) booted from NFS root (NFSv4)
trying to mount UBIFS from NAND/MTD. Board uses VF610 NAND driver.

The MTD partitions are missing entirely (nothing under /dev/mtd).
In the logs you can also see:
[ 1.232161] UBI error: cannot open mtd ubi2, error -2

Attached - dmesg.log

Let me know if you need defconfig or any other information.

Best regards,
Krzysztof
Starting kernel ...

[ 0.000000] Booting Linux on physical CPU 0x0
[ 0.000000] Linux version 4.20.0-rc2-00045-g504ce52176a3 (krzk@PC-kkoz) (gcc version 5.4.0 20160609 (Ubuntu/Linaro 5.4.0-6ubuntu1~16.04.9)) #146 Tue Nov 20 10:37:47 CET 2018
[ 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] random: get_random_bytes called from start_kernel+0x9c/0x3e8 with crng_init=0
[ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 32512
[ 0.000000] Kernel command line: ip=:::::eth0: root=/dev/nfs ubi.mtd=ubi2 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: 103828K/131072K available (6144K kernel code, 196K rwdata, 1636K rodata, 1024K init, 143K bss, 10860K reserved, 16384K cma-reserved)
[ 0.000000] Virtual kernel memory layout:
[ 0.000000] vector : 0xffff0000 - 0xffff1000 ( 4 kB)
[ 0.000000] fixmap : 0xffc00000 - 0xfff00000 (3072 kB)
[ 0.000000] vmalloc : 0x88800000 - 0xff800000 (1904 MB)
[ 0.000000] lowmem : 0x80000000 - 0x88000000 ( 128 MB)
[ 0.000000] modules : 0x7f000000 - 0x80000000 ( 16 MB)
[ 0.000000] .text : 0x(ptrval) - 0x(ptrval) (7136 kB)
[ 0.000000] .init : 0x(ptrval) - 0x(ptrval) (1024 kB)
[ 0.000000] .data : 0x(ptrval) - 0x(ptrval) ( 197 kB)
[ 0.000000] .bss : 0x(ptrval) - 0x(ptrval) ( 144 kB)
[ 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.000054] sched_clock: 64 bits at 132MHz, resolution 7ns, wraps every 2199023255551ns
[ 0.000129] clocksource: arm_global_timer: mask: 0xffffffffffffffff max_cycles: 0x1e7178659b, max_idle_ns: 440795204301 ns
[ 0.000219] Switching to timer-based delay loop, resolution 7ns
[ 0.001345] Console: colour dummy device 80x30
[ 0.002217] printk: console [tty1] enabled
[ 0.002315] Calibrating delay loop (skipped), value calculated using timer frequency.. 264.00 BogoMIPS (lpj=1320000)
[ 0.002417] pid_max: default: 32768 minimum: 301
[ 0.002886] Mount-cache hash table entries: 1024 (order: 0, 4096 bytes)
[ 0.002995] Mountpoint-cache hash table entries: 1024 (order: 0, 4096 bytes)
[ 0.004699] CPU: Testing write buffer coherency: ok
[ 0.007194] Setting up static identity map for 0x80100000 - 0x80100060
[ 0.009976] devtmpfs: initialized
[ 0.024999] VFP support v0.3: implementor 41 architecture 2 part 30 variant 5 rev 1
[ 0.025841] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[ 0.025979] futex hash table entries: 256 (order: -1, 3072 bytes)
[ 0.028333] pinctrl core: initialized pinctrl subsystem
[ 0.031464] NET: Registered protocol family 16
[ 0.035538] DMA: preallocated 256 KiB pool for atomic coherent allocations
[ 0.038365] cpuidle: using governor menu
[ 0.038787] hw-breakpoint: found 2 (+1 reserved) breakpoint and 1 watchpoint registers.
[ 0.038878] hw-breakpoint: maximum watchpoint size is 4 bytes.
[ 0.050463] vf610-pinctrl 40048000.iomuxc: initialized IMX pinctrl driver
[ 0.111300] +V3.3: supplied by 3.3V
[ 0.113562] SCSI subsystem initialized
[ 0.114381] usbcore: registered new interface driver usbfs
[ 0.114669] usbcore: registered new interface driver hub
[ 0.115034] usbcore: registered new device driver usb
[ 0.117541] i2c i2c-0: IMX I2C adapter registered
[ 0.117770] i2c i2c-0: using dma0chan0 (tx) and dma0chan1 (rx) for DMA transfers
[ 0.118475] pps_core: LinuxPPS API ver. 1 registered
[ 0.118557] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@xxxxxxxx>
[ 0.118712] PTP clock support registered
[ 0.122473] clocksource: Switched to clocksource arm_global_timer
[ 0.158925] NET: Registered protocol family 2
[ 0.160638] tcp_listen_portaddr_hash hash table entries: 512 (order: 0, 4096 bytes)
[ 0.160799] TCP established hash table entries: 1024 (order: 0, 4096 bytes)
[ 0.160898] TCP bind hash table entries: 1024 (order: 0, 4096 bytes)
[ 0.160982] TCP: Hash tables configured (established 1024 bind 1024)
[ 0.161469] UDP hash table entries: 256 (order: 0, 4096 bytes)
[ 0.161587] UDP-Lite hash table entries: 256 (order: 0, 4096 bytes)
[ 0.162274] NET: Registered protocol family 1
[ 0.164143] RPC: Registered named UNIX socket transport module.
[ 0.164250] RPC: Registered udp transport module.
[ 0.164303] RPC: Registered tcp transport module.
[ 0.164348] RPC: Registered tcp NFSv4.1 backchannel transport module.
[ 0.166403] hw perfevents: enabled with armv7_cortex_a5 PMU driver, 3 counters available
[ 0.169674] Initialise system trusted keyrings
[ 0.170382] workingset: timestamp_bits=30 max_order=15 bucket_order=0
[ 0.188384] NFS: Registering the id_resolver key type
[ 0.188547] Key type id_resolver registered
[ 0.188609] Key type id_legacy registered
[ 0.188806] ntfs: driver 2.1.32 [Flags: R/W].
[ 0.190409] fuse init (API version 7.28)
[ 0.218967] Key type asymmetric registered
[ 0.219066] Asymmetric key parser 'x509' registered
[ 0.219179] io scheduler noop registered
[ 0.219239] io scheduler deadline registered
[ 0.219779] io scheduler cfq registered (default)
[ 0.219858] io scheduler mq-deadline registered
[ 0.219914] io scheduler kyber registered
[ 0.224242] gpio gpiochip1: (vf610-gpio): detected irqchip that is shared with multiple gpiochips: please fix the driver.
[ 0.225781] gpio gpiochip2: (vf610-gpio): detected irqchip that is shared with multiple gpiochips: please fix the driver.
[ 0.227381] gpio gpiochip3: (vf610-gpio): detected irqchip that is shared with multiple gpiochips: please fix the driver.
[ 0.228977] gpio gpiochip4: (vf610-gpio): detected irqchip that is shared with multiple gpiochips: please fix the driver.
[ 0.234761] 40027000.serial: ttyLP0 at MMIO 0x40027000 (irq = 19, base_baud = 4125000) is a FSL_LPUART
[ 0.812664] printk: console [ttyLP0] enabled
[ 0.818695] 40028000.serial: ttyLP1 at MMIO 0x40028000 (irq = 20, base_baud = 4125000) is a FSL_LPUART
[ 0.830067] 40029000.serial: ttyLP2 at MMIO 0x40029000 (irq = 21, base_baud = 4125000) is a FSL_LPUART
[ 0.844905] brd: module loaded
[ 0.869850] loop: module loaded
[ 0.876402] ->legacy.cmd_ctrl() should be provided
[ 0.881469] vf610_nfc: probe of 400e0000.nand failed with error -22
[ 0.892796] libphy: Fixed MDIO Bus: probed
[ 0.899928] fec 400d1000.ethernet: Linked as a consumer to regulator.1
[ 0.916126] libphy: fec_enet_mii_bus: probed
[ 0.922404] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[ 0.929947] usbcore: registered new interface driver usb-storage
[ 0.936543] usbcore: registered new interface driver usbserial_generic
[ 0.943395] usbserial: USB Serial support registered for generic
[ 0.949602] usbcore: registered new interface driver ftdi_sio
[ 0.955646] usbserial: USB Serial support registered for FTDI USB Serial Device
[ 0.963276] usbcore: registered new interface driver pl2303
[ 0.969029] usbserial: USB Serial support registered for pl2303
[ 0.987745] snvs_rtc 400a7000.snvs:snvs-rtc-lp: rtc core: registered 400a7000.snvs:snvs-rtc-lp as rtc0
[ 0.997650] i2c /dev entries driver
[ 1.006153] imx2-wdt 4003e000.wdog: timeout 60 sec (nowayout=0)
[ 1.013606] sdhci: Secure Digital Host Controller Interface driver
[ 1.019865] sdhci: Copyright(c) Pierre Ossman
[ 1.024422] sdhci-pltfm: SDHCI platform and OF driver helper
[ 1.031660] sdhci-esdhc-imx 400b2000.esdhc: Got CD GPIO
[ 1.066064] mmc0: SDHCI controller on 400b2000.esdhc [400b2000.esdhc] using ADMA
[ 1.076485] vf610-adc 4003b000.adc: Linked as a consumer to regulator.2
[ 1.088686] vf610-adc 400bb000.adc: Linked as a consumer to regulator.2
[ 1.102304] NET: Registered protocol family 17
[ 1.107331] Key type dns_resolver registered
[ 1.111911] Registering SWP/SWPB emulation handler
[ 1.119712] registered taskstats version 1
[ 1.124093] Loading compiled-in X.509 certificates
[ 1.133580] regulator-usbh-vbus GPIO handle specifies active low - ignored
[ 1.140951] VCC_USB[1-4]: supplied by 5V
[ 1.146677] imx_usb 400b4000.usb: Linked as a consumer to regulator.5
[ 1.158056] ci_hdrc ci_hdrc.1: EHCI Host Controller
[ 1.164488] mmc0: new high speed SDHC card at address aaaa
[ 1.172793] ci_hdrc ci_hdrc.1: new USB bus registered, assigned bus number 1
[ 1.181679] mmcblk0: mmc0:aaaa SL16G 14.8 GiB
[ 1.194632] mmcblk0: p1 p2
[ 1.212646] ci_hdrc ci_hdrc.1: USB 2.0 started, EHCI 1.00
[ 1.220419] hub 1-0:1.0: USB hub found
[ 1.224551] hub 1-0:1.0: 1 port detected
[ 1.232161] UBI error: cannot open mtd ubi2, error -2
[ 1.238140] snvs_rtc 400a7000.snvs:snvs-rtc-lp: setting system clock to 1970-01-01 00:29:31 UTC (1771)
[ 1.253116] Micrel KSZ8041 400d1000.ethernet-1:00: attached PHY driver [Micrel KSZ8041] (mii_bus:phy_addr=400d1000.ethernet-1:00, irq=POLL)
[ 1.752571] usb 1-1: new high-speed USB device number 2 using ci_hdrc
[ 3.363428] fec 400d1000.ethernet eth0: Link is Up - 100Mbps/Full - flow control rx/tx
[ 3.422588] Sending DHCP requests ., OK
[ 3.486485] IP-Config: Got DHCP answer from 192.168.10.1, my address is 192.168.10.17
[ 3.494486] IP-Config: Complete:
[ 3.497780] device=eth0, hwaddr=00:14:2d:2c:a1:2e, ipaddr=192.168.10.17, mask=255.255.255.0, gw=192.168.10.1
[ 3.508174] host=192.168.10.17, domain=, nis-domain=(none)
[ 3.514205] bootserver=192.168.10.1, rootserver=192.168.10.1, rootpath=/srv/nfs/colibri_vf,v4,tcp
[ 3.514226] nameserver0=192.168.10.1
[ 3.591985] VFS: Mounted root (nfs4 filesystem) on device 0:13.
[ 3.599610] devtmpfs: mounted
[ 3.610767] Freeing unused kernel memory: 1024K
[ 3.615765] Run /sbin/init as init process
[ 3.651339] random: fast init done
[ 4.688021] systemd[1]: System time before build time, advancing clock.
[ 4.893199] random: systemd: uninitialized urandom read (16 bytes read)
[ 4.941593] 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 )
[ 4.962037] systemd[1]: Detected architecture arm.