Wrt3200acm: sysupgrade falling back

Hello!

I'm building images for my wrt3200acm using openwrt for some weeks. All feeds are enabled. Just a few additional things are configured. Basically I configured luci and openvpn for tunneling. Everything seemed fine and worked smoothly. Since some days when I'm trying to flash a new image, after reboot, it always falls back and boots only the old system.

Question:
Is it possible to mess up the "sysupdate" mech/script? How can I become able to flash images again? How to debug this? What's going on, on my router?

Details:
I shortened the image names such that "openwrt-18.06.4-r7949-7b0877ddd1-mvebu-cortexa9-linksys-wrt3200acm-squashfs-factory.img" becomes "factory.img". So far, I tried:

  • flashing sysupgrade.bin via luci
  • scp sysupgrade.bin to /tmp, then run "sysupgrade -n -v sysupgrade.bin"
  • scp factory.img to /tmp, then run "sysupgrade -n -v -F factory.img"
  • even with 'set -x' inside the /sbin/sysupgrade script, I could not figure out what is actually failing to reboot my new image
  • I also tried flashing offical images (which worked before), now falling back to old image at reboot

git: tag 18.06.5 plus some commits (git: d08a63770c69a6e4a3014246c74245ab41795e3e)
[shows "18.6.4" due to the version string, I typed wrongly in a config]

Via FTDI cable to the serial pins, I logged the following (this is e.g. flashing with an official sysupgrade.bin):

BusyBox v1.28.4 () built-in shell (ash)

  _______                     ________        __
 |       |.-----.-----.-----.|  |  |  |.----.|  |_
 |   -   ||  _  |  -__|     ||  |  |  ||   _||   _|
 |_______||   __|_____|__|__||________||__|  |____|
          |__| W I R E L E S S   F R E E D O M
 -----------------------------------------------------
 OpenWrt 18.06.4, r7947-182b0aff84
 -----------------------------------------------------

root@OpenWrt:/# cd /tmp/

root@OpenWrt:/tmp# sysupgrade -v openwrt-18.06.5-mvebu-cortexa9-linksys-wrt3200acm-squashfs-sysupgrade.bin

Saving config files...
etc/config/dhcp
etc/config/dropbear
etc/config/firewall
etc/config/luci
etc/config/network
etc/config/openvpn
etc/config/p910nd
etc/config/rpcd
etc/config/system
etc/config/sysupgrade.bin
etc/config/ubootenv
etc/config/ucitrack
etc/config/uhttpd
etc/config/wireless
etc/dropbear/authorized_keys
etc/dropbear/dropbear_rsa_host_key
etc/group
etc/hosts
etc/inittab
etc/luci-uploads/.placeholder
etc/openvpn/client.auth
etc/openvpn/client.opvn
etc/opkg/keys/1035ac73cc4e59e3
etc/opkg/keys/5151f69420c3f508
etc/opkg/keys/72a57f2191b211e0
etc/opkg/keys/792d9d9b39f180dc
etc/opkg/keys/9ef4694208102c43
etc/opkg/keys/b26f36ae0f4106d
etc/opkg/keys/b5043e70f9a75cde
etc/opkg/keys/c10b9afab19ee428
etc/opkg/keys/dace9d4df16896bf
etc/opkg/keys/dd6de0d06bbd3d85
etc/opkg/keys/e62a1e1d55f7c415
etc/passwd
etc/profile
etc/rc.local
etc/shadow
etc/shells
etc/ssh/ssh_host_ecdsa_key
etc/ssh/ssh_host_ecdsa_key.pub
etc/ssh/ssh_host_ed25519_key
etc/ssh/ssh_host_ed25519_key.pub
etc/ssh/ssh_host_rsa_key
etc/ssh/ssh_host_rsa_key.pub
etc/sysctl.conf 
etc/uhttpd.crt  
etc/uhttpd.key  
etc/uhttpd.key  
etc/uhttpd.crt  
Commencing upgrade. Closing all shell sessions.
Watchdog handover: fd=3
- watchdog -
killall: telnetd: no process killed
killall: dropbear: no process killed
Sending TERM to remaining processes ... logd rpcd netifd odhcpd sshd tor uhttpd openvpn ntpd dnsmasq hostapd ubusd
[  565.450907] device wlan1 left promiscuous mode
[  565.455444] br-lan: port 2(wlan1) entered disabled state
Sending KILL to remaining processes ...
Switching to ramdisk...
[  570.143274] UBIFS (ubi0:1): background thread "ubifs_bgt0_1" stops
[  570.213584] UBIFS (ubi0:1): un-mount UBI device 0
Performing system upgrade...

BootROM - 1.73  
Booting from NAND flash

General initialization - Version: 1.0.0
AVS selection from EFUSE disabled (Skip reading EFUSE values)
mvSysEnvIsFlavourReduced: TWSI Read of 'flavor' failed
Detected Device ID 6820
High speed PHY - Version: 2.0

Init RD NAS topology Serdes Lane 3 is USB3
Serdes Lane 4 is SGMII
board SerDes lanes topology details:
 | Lane # | Speed|    Type     |
 ------------------------------|
 |   0    |  6   |  SATA0      |
 |   1    |  5   |  PCIe0      |
 |   2    |  6   |  SATA1      |
 |   3    |  5   |  USB3 HOST1 |
 |   4    |  5   |  PCIe1      |
 |   5    |  0   |  SGMII2     |
 -------------------------------
:** Link is Gen1, check the EP capability
PCIe, Idx 0: Link upgraded to Gen2 based on client cpabilities
:** Link is Gen1, check the EP capability
PCIe, Idx 1: remains Gen1
High speed PHY - Ended Successfully
DDR3 Training Sequence - Ver TIP-1.46.0
mvSysEnvGetTopologyUpdateInfo: TWSI Read failed
DDR3 Training Sequence - Switching XBAR Window to FastPath Window
DDR3 Training Sequence - Ended Successfully
Not detected suspend to RAM indication
BootROM: Image checksum verification PASSED


U-Boot 2013.01 (Sep 25 2017 - 11:42:52) Marvell version: 2015_T1.QA.0p16

Boot version : v1.0.0

Board: RD-NAS-88F6820-DDR3
SoC:   MV88F6820 Rev A0
       running 2 CPUs
CPU:   ARM Cortex A9 MPCore (Rev 1) LE
       CPU 0
       CPU    @ 1866 [MHz]
       L2     @ 933 [MHz]
       TClock @ 200 [MHz]
       DDR3    @ 933 [MHz]
       DDR3 32 Bit Width,FastPath Memory Access, DLB Enabled, ECC Disabled
DRAM:  512 MiB  
NAND:  256 MiB  
MMC:   mv_sdh: 0


#### auto_recovery ####
[u_env] get auto_recovery == yes
[u_env] get auto_recovery == yes
[u_env] get boot_part == 1
[u_env] get boot_part_ready == 3
auto_recovery enabled:1, boot_part:1, boot_part_ready:3

[boot_count_read] block:0x220000, size:128KB, records:64
[boot_count_read_record] boot_count:0, next_record:36

[boot_count_write] erase:0, auto_recovery->block_offset:0x220000 offset=0x232000

Updating boot_count ...
[boot_count_write] offset:0x232000 , length:2048
done

PCI-e 0 (IF 0 - bus 0) Root Complex Interface, Detected Link X1, GEN 2.0
PCI-e 1 (IF 1 - bus 1) Root Complex Interface, Detected Link X1, GEN 1.1
USB2.0 0: Host Mode
USB3.0 1: Host Mode
USB3.0 0: Host Mode

Map:   Code:                    0x1feab000:0x1ff75c30
       BSS:                     0x1ffef564
       Stack:                   0x1f9aaf20
       Heap:                    0x1f9ab000:0x1feab000
       U-Boot Environment:      0x00200000:0x00220000 (NAND)

Board configuration detected:
mvEthE6171SwitchBasicInit init
Net:
|  port  | Interface | PHY address  |
|--------|-----------|--------------|
| egiga0 |   RGMII   |     0x01     |
| egiga1 |   SGMII   |     0x00     |
| egiga2 |   SGMII   |   In-Band    |
egiga0 [PRIME], egiga1, egiga2
auto_recovery_check changes bootcmd: run nandboot
Hit any key to stop autoboot:  0

NAND read: device 0 offset 0xa00000, size 0x600000
 6291456 bytes read: OK
## Booting kernel from Legacy Image at 02000000 ...
   Image Name:   ARM OpenWrt Linux-4.14.158
   Created:      2020-01-03   9:27:03 UTC
   Image Type:   ARM Linux Kernel Image (uncompressed)
   Data Size:    2660218 Bytes = 2.5 MiB
   Load Address: 00008000
   Entry Point:  00008000
   Verifying Checksum ... OK
   Loading Kernel Image ... OK
OK

Starting kernel ...

[    0.000000] Booting Linux on physical CPU 0x0
[    0.000000] Linux version 4.14.158 (user@38fdeff08160) (gcc version 7.3.0 (OpenWrt GCC 7.3.0 r7947-182b0aff84)) #0 SMP Fri Jan 3 09:27:03 2020
[    0.000000] CPU: ARMv7 Processor [414fc091] revision 1 (ARMv7), cr=10c5387d
[    0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT aliasing instruction cache
[    0.000000] OF: fdt: Machine model: Linksys WRT3200ACM
[    0.000000] Memory policy: Data cache writealloc
[    0.000000] random: get_random_bytes called from start_kernel+0x78/0x49c with crng_init=0
[    0.000000] percpu: Embedded 11 pages/cpu s14668 r8192 d22196 u45056
[    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 129920
[    0.000000] Kernel command line: console=ttyS0,115200 root=/dev/mtdblock6 ro rootdelay=1 rootfstype=jffs2 earlyprintk mtdparts=armada-nand:2048K(uboot)ro,128K(u_env),256K(s_env),256K@8064K(devinfo),1920K@8320K(sysdiag),80m@10m(kernel),74m@16m(rootfs),80m@90m(alt_kernel),74m@96m(alt_rootfs),160m@10m(ubifs),-@170m(syscfg)
[    0.000000] Bootloader command line (ignored): console=ttyS0,115200 root=/dev/mtdblock6 ro rootdelay=1 rootfstype=jffs2 earlyprintk mtdparts=armada-nand:2048K(uboot)ro,128K(u_env),256K(s_env),256K@8064K(devinfo),1920K@8320K(sysdiag),80m@10m(kernel),74m@16m(rootfs),80m@90m(alt_kernel),74m@96m(alt_rootfs),160m@10m(ubifs),-@170m(syscfg)
[    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: 509400K/524288K available (6144K kernel code, 205K rwdata, 1408K rodata, 1024K init, 231K bss, 14888K reserved, 0K cma-reserved, 0K highmem)
[    0.000000] Virtual kernel memory layout:
[    0.000000]     vector  : 0xffff0000 - 0xffff1000   (   4 kB)
[    0.000000]     fixmap  : 0xffc00000 - 0xfff00000   (3072 kB)
[    0.000000]     vmalloc : 0xe0800000 - 0xff800000   ( 496 MB)
[    0.000000]     lowmem  : 0xc0000000 - 0xe0000000   ( 512 MB)
[    0.000000]     pkmap   : 0xbfe00000 - 0xc0000000   (   2 MB)
[    0.000000]     modules : 0xbf000000 - 0xbfe00000   (  14 MB)
[    0.000000]       .text : 0xc0008000 - 0xc0700000   (7136 kB)
[    0.000000]       .init : 0xc0900000 - 0xc0a00000   (1024 kB)
[    0.000000]       .data : 0xc0a00000 - 0xc0a33580   ( 206 kB)
[    0.000000]        .bss : 0xc0a33580 - 0xc0a6d498   ( 232 kB)
[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=2, Nodes=1
[    0.000000] Hierarchical RCU implementation.
[    0.000000]  RCU restricting CPUs from NR_CPUS=4 to nr_cpu_ids=2.
[    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 enabling early BRESP for Cortex-A9
[    0.000000] L2C-310 full line of zeros enabled for Cortex-A9
[    0.000000] L2C-310 D prefetch enabled, offset 1 lines
[    0.000000] L2C-310 dynamic clock gating enabled, standby mode enabled
[    0.000000] L2C-310 Coherent cache controller enabled, 16 ways, 1024 kB
[    0.000000] L2C-310 Coherent: CACHE_ID 0x410054c9, AUX_CTRL 0x56070001
[    0.000005] sched_clock: 64 bits at 933MHz, resolution 1ns, wraps every 4398046511103ns
[    0.000014] clocksource: arm_global_timer: mask: 0xffffffffffffffff max_cycles: 0x1ae5b571769, max_idle_ns: 881590513431 ns
[    0.000025] Switching to timer-based delay loop, resolution 1ns
[    0.000122] Ignoring duplicate/late registration of read_current_timer delay
[    0.000128] clocksource: armada_370_xp_clocksource: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 76450417870 ns
[    0.000241] Calibrating delay loop (skipped), value calculated using timer frequency.. 1866.00 BogoMIPS (lpj=9330000)
[    0.000248] pid_max: default: 32768 minimum: 301
[    0.000302] Mount-cache hash table entries: 1024 (order: 0, 4096 bytes)
[    0.000306] Mountpoint-cache hash table entries: 1024 (order: 0, 4096 bytes)
[    0.000556] CPU: Testing write buffer coherency: ok
[    0.000566] CPU0: Spectre v2: using BPIALL workaround
[    0.000665] CPU0: thread -1, cpu 0, socket 0, mpidr 80000000
[    0.000767] Setting up static identity map for 0x100000 - 0x100060
[    0.000826] mvebu-soc-id: MVEBU SoC ID=0x6820, Rev=0x4
[    0.000887] mvebu-pmsu: Initializing Power Management Service Unit
[    0.000928] Hierarchical SRCU implementation.
[    0.001089] smp: Bringing up secondary CPUs ...
[    0.001193] Booting CPU 1
[    0.001330] CPU1: thread -1, cpu 1, socket 0, mpidr 80000001
[    0.001333] CPU1: Spectre v2: using BPIALL workaround
[    0.001377] smp: Brought up 1 node, 2 CPUs
[    0.001381] SMP: Total of 2 processors activated (3732.00 BogoMIPS).
[    0.001384] CPU: All CPU(s) started in SVC mode.
[    0.002785] VFP support v0.3: implementor 41 architecture 3 part 30 variant 9 rev 4
[    0.002830] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[    0.002837] futex hash table entries: 512 (order: 3, 32768 bytes)
[    0.002897] pinctrl core: initialized pinctrl subsystem
[    0.003126] NET: Registered protocol family 16
[    0.003606] DMA: preallocated 256 KiB pool for atomic coherent allocations
[    0.004184] cpuidle: using governor ladder
[    0.004322] mvebu-pmsu: CPU hotplug support is currently broken on Armada 38x: disabling
[    0.004328] mvebu-pmsu: CPU idle is currently broken on Armada 38x: disabling
[    0.009531] reg-fixed-voltage usb3_1-vbus: could not find pctldev for node /soc/internal-regs/pinctrl@18000/usb3_1-vbus-pins, deferring probe
[    0.009685] SCSI subsystem initialized
[    0.009874] usbcore: registered new interface driver usbfs
[    0.009897] usbcore: registered new interface driver hub
[    0.009919] usbcore: registered new device driver usb
[    0.010494] clocksource: Switched to clocksource arm_global_timer
[    0.010842] NET: Registered protocol family 2
[    0.011035] TCP established hash table entries: 4096 (order: 2, 16384 bytes)
[    0.011055] TCP bind hash table entries: 4096 (order: 3, 32768 bytes)
[    0.011083] TCP: Hash tables configured (established 4096 bind 4096)
[    0.011116] UDP hash table entries: 256 (order: 1, 8192 bytes)
[    0.011130] UDP-Lite hash table entries: 256 (order: 1, 8192 bytes)
[    0.011190] NET: Registered protocol family 1
[    0.012004] Crashlog allocated RAM at address 0x3f00000
[    0.012061] workingset: timestamp_bits=14 max_order=17 bucket_order=3
[    0.013734] squashfs: version 4.0 (2009/01/31) Phillip Lougher
[    0.013740] jffs2: version 2.2 (NAND) (SUMMARY) (LZMA) (RTIME) (CMODE_PRIORITY) (c) 2001-2006 Red Hat, Inc.
[    0.014987] io scheduler noop registered
[    0.014993] io scheduler deadline registered (default)
[    0.015390] armada-38x-pinctrl f1018000.pinctrl: registered pinctrl driver
[    0.016256] mvebu-pcie soc:pcie: PCI host bridge to bus 0000:00
[    0.016266] pci_bus 0000:00: root bus resource [io  0x1000-0xfffff]
[    0.016270] pci_bus 0000:00: root bus resource [mem 0xe0000000-0xe7ffffff]
[    0.016274] pci_bus 0000:00: root bus resource [bus 00-ff]
[    0.016431] PCI: bus0: Fast back to back transfers disabled
[    0.016437] pci 0000:00:01.0: bridge configuration invalid ([bus 00-00]), reconfiguring
[    0.016443] pci 0000:00:02.0: bridge configuration invalid ([bus 00-00]), reconfiguring
[    0.016630] PCI: bus1: Fast back to back transfers disabled
[    0.016853] PCI: bus2: Fast back to back transfers disabled
[    0.016875] pci 0000:00:01.0: BAR 8: assigned [mem 0xe0000000-0xe02fffff]
[    0.016880] pci 0000:00:02.0: BAR 8: assigned [mem 0xe0400000-0xe06fffff]
[    0.016885] pci 0000:01:00.0: BAR 0: assigned [mem 0xe0000000-0xe01fffff 64bit pref]
[    0.016894] pci 0000:01:00.0: BAR 2: assigned [mem 0xe0200000-0xe02fffff 64bit pref]
[    0.016902] pci 0000:00:01.0: PCI bridge to [bus 01]
[    0.016907] pci 0000:00:01.0:   bridge window [mem 0xe0000000-0xe02fffff]
[    0.016914] pci 0000:02:00.0: BAR 0: assigned [mem 0xe0400000-0xe05fffff 64bit pref]
[    0.016923] pci 0000:02:00.0: BAR 2: assigned [mem 0xe0600000-0xe06fffff 64bit pref]
[    0.016932] pci 0000:00:02.0: PCI bridge to [bus 02]
[    0.016936] pci 0000:00:02.0:   bridge window [mem 0xe0400000-0xe06fffff]
[    0.017139] mv_xor f1060800.xor: Marvell shared XOR driver
[    0.061073] mv_xor f1060800.xor: Marvell XOR (Descriptor Mode): ( xor cpy intr )
[    0.061178] mv_xor f1060900.xor: Marvell shared XOR driver
[    0.120872] mv_xor f1060900.xor: Marvell XOR (Descriptor Mode): ( xor cpy intr )
[    0.121018] Serial: 8250/16550 driver, 2 ports, IRQ sharing disabled
[    0.121265] console [ttyS0] disabled
[    0.141327] f1012000.serial: ttyS0 at MMIO 0xf1012000 (irq = 22, base_baud = 12500000) is a 16550A
[    0.919499] console [ttyS0] enabled
[    0.924353] loop: module loaded
[    0.927780] ahci-mvebu f10a8000.sata: AHCI 0001.0000 32 slots 2 ports 6 Gbps 0x3 impl platform mode
[    0.936882] ahci-mvebu f10a8000.sata: flags: 64bit ncq sntf led only pmp fbs pio slum part sxs
[    0.946004] scsi host0: ahci-mvebu
[    0.949566] scsi host1: ahci-mvebu
[    0.953101] ata1: SATA max UDMA/133 mmio [mem 0xf10a8000-0xf10a9fff] port 0x100 irq 41
[    0.961059] ata2: SATA max UDMA/133 mmio [mem 0xf10a8000-0xf10a9fff] port 0x180 irq 41
[    0.969368] pxa3xx-nand f10d0000.flash: This platform can't do DMA on this device
[    0.977169] nand: device found, Manufacturer ID: 0xef, Chip ID: 0xda
[    0.983558] nand: Winbond W29N02GV
[    0.986974] nand: 256 MiB, SLC, erase size: 128 KiB, page size: 2048, OOB size: 64
[    0.994599] pxa3xx-nand f10d0000.flash: ECC strength 16, ECC step size 2048
[    1.001778] Bad block table found at page 131008, version 0x01
[    1.007957] Bad block table found at page 130944, version 0x01
[    1.014084] 11 fixed-partitions partitions found on MTD device pxa3xx_nand-0
[    1.021171] Creating 11 MTD partitions on "pxa3xx_nand-0":
[    1.026681] 0x000000000000-0x000000200000 : "u-boot"
[    1.031896] 0x000000200000-0x000000220000 : "u_env"
[    1.036963] 0x000000220000-0x000000260000 : "s_env"
[    1.042035] 0x0000007e0000-0x000000820000 : "devinfo"
[    1.047270] 0x000000820000-0x000000a00000 : "sysdiag"
[    1.052520] 0x000000a00000-0x000005a00000 : "kernel1"
[    1.057904] 0x000001000000-0x000005a00000 : "ubi"
[    1.062946] 0x000005a00000-0x00000aa00000 : "kernel2"
[    1.068328] 0x000006000000-0x00000aa00000 : "rootfs2"
[    1.073714] 0x00000aa00000-0x000010000000 : "syscfg"
[    1.079015] 0x000000260000-0x000000820000 : "unused_area"
[    1.084907] libphy: Fixed MDIO Bus: probed
[    1.089292] libphy: orion_mdio_bus: probed
[    1.093565] mvneta_bm f10c8000.bm: Buffer Manager for network controller enabled
[    1.102209] mvneta f1070000.ethernet eth0: Using hardware mac address 24:f5:a2:c5:ac:b0
[    1.111411] mvneta f1034000.ethernet eth1: Using hardware mac address 24:f5:a2:c5:ac:b0
[    1.119589] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[    1.126153] ehci-platform: EHCI generic platform driver
[    1.131465] ehci-orion: EHCI orion driver
[    1.135570] orion-ehci f1058000.usb: EHCI Host Controller
[    1.141006] orion-ehci f1058000.usb: new USB bus registered, assigned bus number 1
[    1.148646] orion-ehci f1058000.usb: irq 38, io mem 0xf1058000
[    1.180489] orion-ehci f1058000.usb: USB 2.0 started, EHCI 1.00
[    1.186632] hub 1-0:1.0: USB hub found
[    1.190409] hub 1-0:1.0: 1 port detected
[    1.194719] usbcore: registered new interface driver usb-storage
[    1.200897] i2c /dev entries driver
[    1.215650] (NULL device *): hwmon_device_register() is deprecated. Please convert the driver to use hwmon_device_register_with_info().
[    1.228078] orion_wdt: Initial timeout 171 sec
[    1.232760] sdhci: Secure Digital Host Controller Interface driver
[    1.238967] sdhci: Copyright(c) Pierre Ossman
[    1.291777] ata1: SATA link down (SStatus 0 SControl 300)
[    1.297226] ata2: SATA link down (SStatus 0 SControl 300)
[    1.310496] mmc0: SDHCI controller on f10d8000.sdhci [f10d8000.sdhci] using ADMA
[    1.318009] sdhci-pltfm: SDHCI platform and OF driver helper
[    1.329928] marvell-cesa f1090000.crypto: CESA device successfully registered
[    1.337491] NET: Registered protocol family 10
[    1.342390] Segment Routing with IPv6
[    1.346100] NET: Registered protocol family 17
[    1.350691] 8021q: 802.1Q VLAN Support v1.8
[    1.354950] Registering SWP/SWPB emulation handler
[    1.361188] xhci-hcd f10f8000.usb3: xHCI Host Controller
[    1.366534] xhci-hcd f10f8000.usb3: new USB bus registered, assigned bus number 2
[    1.374124] xhci-hcd f10f8000.usb3: hcc params 0x0a000990 hci version 0x100 quirks 0x0000000000010010
[    1.383427] xhci-hcd f10f8000.usb3: irq 44, io mem 0xf10f8000
[    1.389478] hub 2-0:1.0: USB hub found
[    1.393280] hub 2-0:1.0: 1 port detected
[    1.397317] xhci-hcd f10f8000.usb3: xHCI Host Controller
[    1.402668] xhci-hcd f10f8000.usb3: new USB bus registered, assigned bus number 3
[    1.410191] xhci-hcd f10f8000.usb3: Host supports USB 3.0  SuperSpeed
[    1.416698] usb usb3: We don't know the algorithms for LPM for this host, disabling LPM.
[    1.424986] hub 3-0:1.0: USB hub found
[    1.428780] hub 3-0:1.0: 1 port detected
[    1.433075] UBI: auto-attach mtd6
[    1.436406] ubi0: attaching mtd6
[    1.445460] random: fast init done
[    1.463102] mmc0: new high speed SDIO card at address 0001
[    1.640611] ubi0: scanning is finished
[    1.648606] ubi0: attached mtd6 (name "ubi", size 74 MiB)
[    1.654036] ubi0: PEB size: 131072 bytes (128 KiB), LEB size: 126976 bytes
[    1.660944] ubi0: min./max. I/O unit sizes: 2048/2048, sub-page size 2048
[    1.667761] ubi0: VID header offset: 2048 (aligned 2048), data offset: 4096
[    1.674755] ubi0: good PEBs: 592, bad PEBs: 0, corrupted PEBs: 0
[    1.680789] ubi0: user volume: 2, internal volumes: 1, max. volumes count: 128
[    1.688043] ubi0: max/mean erase counter: 2/0, WL threshold: 4096, image sequence number: 1703301755
[    1.697217] ubi0: available PEBs: 0, total reserved PEBs: 592, PEBs reserved for bad PEB handling: 40
[    1.706483] ubi0: background thread "ubi_bgt0d" started, PID 702
[    1.712887] block ubiblock0_0: created from ubi0:0(rootfs)
[    1.718396] ubiblock: device ubiblock0_0 (rootfs) set to be root filesystem
[    1.725586] mvsw61xx 10.mvsw61xx: Found MV88E6352 at f1072004.mdio-mii:10
[    1.732411] mvsw61xx 10.mvsw61xx: Using direct addressing
[    1.744778] hctosys: unable to open rtc device (rtc0)
[    1.750099] Waiting 1 sec before mounting root device...
[    2.792065] VFS: Mounted root (squashfs filesystem) readonly on device 254:0.
[    2.799712] Freeing unused kernel memory: 1024K
[    2.951457] init: Console is alive
[    2.954933] init: - watchdog -
[    3.171788] kmodloader: loading kernel modules from /etc/modules-boot.d/*
[    3.214656] kmodloader: done loading kernel modules from /etc/modules-boot.d/*
[    3.229993] init: - preinit -
[    3.381812] mvneta f1070000.ethernet tmp0: renamed from eth0
[    3.387763] random: procd: uninitialized urandom read (4 bytes read)
[    3.431874] mvneta f1034000.ethernet eth0: renamed from eth1
[    3.471735] mvneta f1070000.ethernet eth1: renamed from tmp0
Press the [f] key and hit [enter] to enter failsafe mode
Press the [1], [2], [3] or [4] key and hit [enter] to select the debug level
[    6.601389] UBIFS (ubi0:1): background thread "ubifs_bgt0_1" started, PID 781
[    6.642168] UBIFS (ubi0:1): UBIFS: mounted UBI device 0, volume 1, name "rootfs_data"
[    6.650035] UBIFS (ubi0:1): LEB size: 126976 bytes (124 KiB), min./max. I/O unit sizes: 2048 bytes/2048 bytes
[    6.660004] UBIFS (ubi0:1): FS size: 61202432 bytes (58 MiB, 482 LEBs), journal size 3047424 bytes (2 MiB, 24 LEBs)
[    6.670490] UBIFS (ubi0:1): reserved for root: 2890741 bytes (2822 KiB)
[    6.677134] UBIFS (ubi0:1): media format: w4/r0 (latest is w5/r0), UUID BC2F37DE-2101-4D25-8BCE-BEEF3BD5CB89, small LPT model
[    6.690293] mount_root: switching to ubifs overlay
[    6.729863] ubi1: attaching mtd9
[    6.850975] random: crng init done
[    6.955936] ubi1: scanning is finished
[    6.963981] ubi1: attached mtd9 (name "syscfg", size 86 MiB)
[    6.969668] ubi1: PEB size: 131072 bytes (128 KiB), LEB size: 126976 bytes
[    6.976583] ubi1: min./max. I/O unit sizes: 2048/2048, sub-page size 2048
[    6.983404] ubi1: VID header offset: 2048 (aligned 2048), data offset: 4096
[    6.990396] ubi1: good PEBs: 680, bad PEBs: 8, corrupted PEBs: 0
[    6.996431] ubi1: user volume: 1, internal volumes: 1, max. volumes count: 128
[    7.003687] ubi1: max/mean erase counter: 5/2, WL threshold: 4096, image sequence number: 1682123465
[    7.012866] ubi1: available PEBs: 0, total reserved PEBs: 680, PEBs reserved for bad PEB handling: 32
[    7.022133] ubi1: background thread "ubi_bgt1d" started, PID 789
UBI device number 1, total 680 LEBs (86343680 by[    7.032128] UBIFS (ubi1:0): background thread "ubifs_bgt1_0" started, PID 795
tes, 82.3 MiB), available 0 LEBs (0 bytes), LEB size 126976 bytes (124.0 KiB)
[    7.052535] UBIFS (ubi1:0): recovery needed
[    7.124712] UBIFS (ubi1:0): recovery completed
[    7.129204] UBIFS (ubi1:0): UBIFS: mounted UBI device 1, volume 0, name "syscfg"
[    7.136643] UBIFS (ubi1:0): LEB size: 126976 bytes (124 KiB), min./max. I/O unit sizes: 2048 bytes/2048 bytes
[    7.146631] UBIFS (ubi1:0): FS size: 80375808 bytes (76 MiB, 633 LEBs), journal size 4063232 bytes (3 MiB, 32 LEBs)
[    7.157117] UBIFS (ubi1:0): reserved for root: 3796347 bytes (3707 KiB)
[    7.163764] UBIFS (ubi1:0): media format: w4/r0 (latest is w5/r0), UUID 0B0BA344-3B0F-406D-A663-B913498C90B5, small LPT model
[    7.176391] urandom-seed: Seeding with /etc/urandom.seed
[    7.215694] procd: - early -
[    7.218607] procd: - watchdog -
[    7.821796] procd: - watchdog -
[    7.825032] procd: - ubus -
[    7.878992] procd: - init -
Please press Enter to activate this console.
[    7.997822] kmodloader: loading kernel modules from /etc/modules.d/*
[    8.030399] tun: Universal TUN/TAP device driver, 1.6
[    8.036717] ip6_tables: (C) 2000-2006 Netfilter Core Team
[    8.045905] nf_conntrack version 0.5.0 (8192 buckets, 32768 max)
[    8.057798] Loading modules backported from Linux version wt-2017-11-01-0-gfe248fc2c180
[    8.065898] Backport generated by backports.git v4.14-rc2-1-31-g86cf0e5d
[    8.081279] <<Marvell Mac80211 Wireless PCIE Network Driver version 10.3.8.0-20181114>>
[    8.089331] pci 0000:00:01.0: enabling device (0140 -> 0142)
[   11.156522] ieee80211 phy0: device node: /soc/pcie/pcie@1,0
[   11.189505] ieee80211 phy0: firmware version: 0x9030206
[   11.496495] ieee80211 phy0: firmware region code: 30
[   11.535332] ieee80211 phy0: 2G disabled, 5G enabled
[   11.540238] ieee80211 phy0: 4 TX antennas, 4 RX antennas
[   11.545774] pci 0000:00:02.0: enabling device (0140 -> 0142)
[   12.896522] ieee80211 phy1: device node: /soc/pcie/pcie@2,0
[   12.929503] ieee80211 phy1: firmware version: 0x9030206
[   13.236495] ieee80211 phy1: firmware region code: 30
[   13.269357] ieee80211 phy1: 2G enabled, 5G disabled
[   13.274291] ieee80211 phy1: 4 TX antennas, 4 RX antennas
[   13.282697] hidraw: raw HID events driver (C) Jiri Kosina
[   13.289353] arp_tables: arp_tables: (C) 2002 David S. Miller
[   13.296702] ip_tables: (C) 2000-2006 Netfilter Core Team
[   13.324586] wireguard: WireGuard 0.0.20190601 loaded. See www.wireguard.com for information.
[   13.333103] wireguard: Copyright (C) 2015-2019 Jason A. Donenfeld <Jason@zx2c4.com>. All Rights Reserved.
[   13.378778] xt_time: kernel timezone is -0000
[   13.385310] PPP generic driver version 2.4.2
[   13.390092] NET: Registered protocol family 24
[   13.395543] kmodloader: done loading kernel modules from /etc/modules.d/*
[   14.354258] mwifiex_sdio mmc0:0001:1: info: FW download over, size 695532 bytes
[   14.846962] mvneta f1034000.ethernet eth0: configuring for fixed/sgmii link mode
[   14.854823] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
[   14.860835] mwifiex_sdio mmc0:0001:1: WLAN FW is active
[   14.866102] mvneta f1034000.ethernet eth0: Link is Up - 1Gbps/Full - flow control off
[   14.874195] br-lan: port 1(eth0.1) entered blocking state
[   14.879626] br-lan: port 1(eth0.1) entered disabled state
[   14.885192] device eth0.1 entered promiscuous mode
[   14.890004] device eth0 entered promiscuous mode
[   14.894960] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
[   14.902822] br-lan: port 1(eth0.1) entered blocking state
[   14.908262] br-lan: port 1(eth0.1) entered forwarding state
[   14.913954] IPv6: ADDRCONF(NETDEV_UP): br-lan: link is not ready
[   14.922340] mwifiex_sdio mmc0:0001:1: CMD_RESP: cmd 0x242 error, result=0x2
[   14.929355] mwifiex_sdio mmc0:0001:1: mwifiex_process_cmdresp: cmd 0x242 failed during       initialization
[   14.942112] mvneta f1070000.ethernet eth1: configuring for fixed/rgmii-id link mode
[   14.950196] IPv6: ADDRCONF(NETDEV_UP): eth1: link is not ready
[   14.956306] mvneta f1070000.ethernet eth1: Link is Up - 1Gbps/Full - flow control off
[   14.998457] IPv6: ADDRCONF(NETDEV_CHANGE): eth1: link becomes ready
[   15.012783] mwifiex_sdio mmc0:0001:1: info: MWIFIEX VERSION: mwifiex 1.0 (15.68.7.p71)
[   15.020843] mwifiex_sdio mmc0:0001:1: driver_version = mwifiex 1.0 (15.68.7.p71)
[   16.047758] IPv6: ADDRCONF(NETDEV_UP): wlan1: link is not ready
[   16.053891] IPv6: ADDRCONF(NETDEV_CHANGE): br-lan: link becomes ready
[   16.063789] br-lan: port 2(wlan1) entered blocking state
[   16.069139] br-lan: port 2(wlan1) entered disabled state
[   16.074621] device wlan1 entered promiscuous mode
[   21.279510] IPv6: ADDRCONF(NETDEV_CHANGE): wlan1: link becomes ready
[   21.285962] br-lan: port 2(wlan1) entered blocking state
[   21.291304] br-lan: port 2(wlan1) entered forwarding state

This is my first post here. A huge thank you to the community!!! Documentation so far made many things quite easy.

What happens if you use -F on the sysupgrade image.
Can you manually force it to the other partition:

Summary
#!/bin/sh
#hacked from /lib/upgrade/linksys.sh

cur_boot_part=`/usr/sbin/fw_printenv -n boot_part`
target_firmware=""
if [ "$cur_boot_part" = "1" ]
then
    target_firmware="kernel2"
    fw_setenv boot_part 2
    fw_setenv bootcmd "run altnandboot"
elif [ "$cur_boot_part" = "2" ]
then
    target_firmware="kernel1"
    fw_setenv boot_part 1
    fw_setenv bootcmd "run nandboot"
fi
# re-enable recovery so we get back if the new firmware is broken
fw_setenv auto_recovery yes
echo "$target_firmware"
reboot

If I remember right, I once had the same problem. What helped me, is first to flash the original Linksys firmware again, which get installed on the other partition (the one the update should go to as well). Then I booted back into my OpenWrt partion, and tried the upgrade process again, which worked at this point.

I figured that something must have been screwed up on the partition I wanted to install to update onto. Temporarly going back to the official firmware fixed that.

Unfortunately, there's no difference i.e. falls back to the installed system at next boot.

I tried your script - thank you!! - I think it helps me a lot for better understanding how openWrt works. The script is not working, though, for me. Nevertheless, it gives me an error:

root@OpenWrt:/tmp# ./manual-sysupgrade.sh
Cannot parse config file '/etc/fw_env.config': No such file or directory
Cannot parse config file '/etc/fw_env.config': No such file or directory
Error: environment not initialized

So I got a starting point! Seems like the other partition is somehow corrupt, as also MagicSimi mentioned (thanks).

I tried it today, no success... thanks anyway!

Given this I went into u-boot shell, to see a little how all is set up. I could fetch an image via tftp, but didn't dare to write any partition so far. BTW is there a howto, or a wiki site which explaines, how to "sysupgrade" manually from off the u-boot environment? Or, do I have to understand the sysupgrade tool/script and figure it out how myself? Anyone who did that once, in case to recover? I'm pretty sure to be able to write the nand flash manually from off u-boot. In case of figuring out it could become painfull.

I further tried to set variables, such as "boot_part" to 2 manually in u-boot and boot up, but same result. I tried to reset the u-boot env already without success.

BTW, when performing sysupgrade (as above), I noticed the following:

#### auto_recovery ####
[u_env] get auto_recovery == yes
[u_env] get auto_recovery == yes
[u_env] get boot_part == 1
[u_env] get boot_part_ready == 3
auto_recovery enabled:1, boot_part:1, boot_part_ready:3

Might this be the place where it falls back?

Further I saw in the bootlog the following partitions:

[    1.021025] Creating 11 MTD partitions on "pxa3xx_nand-0":
[    1.026536] 0x000000000000-0x000000200000 : "u-boot"
[    1.031736] 0x000000200000-0x000000220000 : "u_env"
[    1.036799] 0x000000220000-0x000000260000 : "s_env"
[    1.041876] 0x0000007e0000-0x000000820000 : "devinfo"
[    1.047114] 0x000000820000-0x000000a00000 : "sysdiag"
[    1.052376] 0x000000a00000-0x000005a00000 : "kernel1"
[    1.057758] 0x000001000000-0x000005a00000 : "ubi"
[    1.062788] 0x000005a00000-0x00000aa00000 : "kernel2"
[    1.068176] 0x000006000000-0x00000aa00000 : "rootfs2"
[    1.073553] 0x00000aa00000-0x000010000000 : "syscfg"
[    1.078862] 0x000000260000-0x000000820000 : "unused_area"

Is this normal/OK? Actually, I understand rootfs2 as ro root partition, and thought of it as a squashfs partition, then ubi is a rw overlay, and that there should always be also an old "rootfs" (pri/alt) as it is the case e.g. with the kernel. If so where is "rootfs1"? What am I missing?

For some reason your missing fw_env.config... to begin with best to recreate it... Not familiar with that platform... but the right values can be found ( package/boot/uboot-envtools/files/mvebu )... ( only the inverted comma sections )... best to wait for someone with the device to paste one for you...

Yes, that is normal

ubi corresponds to the other rootfs (rootfs1)

The active kernel's rootfs is called ubi, while the passive kernel's corresponding rootfs is called rootfsX. Once the dualboot is switched to the other kernel, the shown naming changes.

That should not be relevant. In a sysupgrade you always flash the other partition and switch booting to it for the reboot. Even if it would be corrupt, it would be overwritten in the sysupgrade. But still, if the first block of it would be damaged and that would prevent ubifs from working???

Your bootlog looked normal, pretty much like in my own WRT3200ACM.

But you have a "new device" with new flash chip (Winbond), which was originally not supported, and the support was introduced in 2018. I think that you should move to 19.07 series in any case.

You could analyse what you have currently on the other partition:

root@router3:~# strings /dev/mtd5  | head -n 2
ARM OpenWrt Linux-4.19.93
EEEE@_

root@router3:~# strings /dev/mtd7  | head -n 2
ARM OpenWrt Linux-4.14.162
@ #!

I have OpenWrt master on the first mtd5 partition (kernel 4.19) and the other one has 19.07 (kernel 4.14). If there would be the OEM Linksys firmware, it would be "Linksys WRT3200 Router".

There is also luci-app-advanced-reboot app that would show you the same info and offer boot possibilities. You might test it.

You might also try flashing the Linksys firmware, with force option like "sysupgrade -F image.img".

And in all cases, please verify the SHA256 of the image before flashing. (especially important in LuCI as 18.06.4 has a bug in LuCI file transfer)

There are instructions on how to tftp this device on the wiki, I would ignore the bit about flashing the same image to both partitions.

root@bsaedgy:/etc# /usr/sbin/fw_printenv -n boot_part
1
root@bsaedgy:/etc# cat fw_env.config 
/dev/mtd1 0x0 0x20000 0x20000 

Sorry for the late response! My wife (currently pregnant, thus currently with a very low stress tolerance) got a bit upset about not working internet. Had to change plans: first fix up an old router for internet! :slight_smile:

Long story short:

  1. PC: tftp server on /srv/tftp/ on eth0 192.168.123.160/24 - I moved a firmware.img to /srv/tftp

  2. stopped router at u-boot

Marvell>> setenv ipaddr 192.168.123.1
Marvell>> setenv serverip 192.168.123.160
Marvell>> setenv netmask 255.255.255.0
Marvell>> ping 192.168.123.160
    alive!
  1. flash "firmware.img"
Marvell>> run flash_pri_image

this is implicitely performing the following (u-boot resolves $filesize):

    => tftp 0x2000000 rango.img
    => nand erase 0x0a00000 0x5000000
    => nand write 0x2000000 0x0a00000 $filesize
  1. booting via 'reset'
Marvell>> reset

BTW. first I tried with "kernel+initramfs.bin" instead of the firmware image, since I thought it should be ok (addresses start at the specific kernel) - it was no problem, booted up, but after power cycling the router, u-boot started to "CRC check of kernel failed". Hence, I started tftp-booting the kernel, then on the running system playing with sysupgrade and '-F', but this could not really change the situation. Finally I flashed the "firmware.img" in u-boot as described above, and it worked out.

The following might become another Thread:

About /etc/fw_env.config: it is still not there. Can it be, that I did not install the u-boot-tools, I remember something about fw_env issues from another project?

Then I saw my u-boot seems to be quite old, is this ok? Why not upgrading u-boot?

Marvell>> version

U-Boot 2013.01 (Sep 25 2017 - 11:42:52) Marvell version: 2015_T1.QA.0p16

Boot version : v1.0.0
arm-marvell-linux-gnueabi-gcc (Linaro GCC branch-4.6.4. Marvell GCC 201301-1645.aee66e26) 4.6.4 20120731 (prerelease)
GNU ld (Linaro GCC branch-4.6.4. Marvell GCC 201301-1645.aee66e26) 2.22.0.20120801

Anyway, my problem seems to be solved. Thank you so much! I think all of your hints brought me on the right track, without I would have been totally lost!!

BTW. I found ./build_dir/target-arm_cortex-a9+vfpv3_musl_eabi/u-boot-2018.03/tools/env/fw_env.config under the build files, I copied it to /etc/fw_env.config onto the router, and fw_printenv works again. Still I have the impression that sysupgrade -n -v or even sysupgrade -F does not wipe out a config and reflashes everything. The u-boot apporach as above, for me works more thoroughly, somehow. Perhaps there is still some hidden bug.

This topic was automatically closed 10 days after the last reply. New replies are no longer allowed.