Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

FS#3206 - sysupgrade from 18.06.8 to 19.07.0..trunk results in a boot loop on Ubiquiti ER-X-SFP #8033

Closed
openwrt-bot opened this issue Jun 27, 2020 · 4 comments
Labels

Comments

@openwrt-bot
Copy link

openwrt-bot commented Jun 27, 2020

whitequark:

After a sysupgrade from 18.06.8 to 19.07.0, 19.07.3, or trunk as of 2020-06-28, the router is stuck in an UBI-related boot loop.

Boot log for trunk:

===================================================================
                MT7621   stage1 code 10:33:11 (ASIC)
                CPU=50000000 HZ BUS=16666666 HZ
==================================================================
Change MPLL source from XTAL to CR...
do MEMPLL setting..
MEMPLL Config : 0x11100000
3PLL mode + External loopback
=== XTAL-40Mhz === DDR-1200Mhz ===
PLL2 FB_DL: 0xf, 1/0 = 634/390 3D000000
PLL4 FB_DL: 0x14, 1/0 = 514/510 51000000
PLL3 FB_DL: 0x1a, 1/0 = 703/321 69000000
do DDR setting..[00320381]
Apply DDR3 Setting...(use customer AC)
          0    8   16   24   32   40   48   56   64   72   80   88   96  104  112  120
W: g.applet.interface.uart: 3173 frame or parity errors detected
      --------------------------------------------------------------------------------
0000:|    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
0001:|    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
0002:|    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
0003:|    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
0004:|    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
0005:|    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
0006:|    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
0007:|    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
0008:|    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
0009:|    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
000A:|    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
000B:|    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
000C:|    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
000D:|    0    0    0    0    0    0    0    0    0    0    0    0    0    1    1    1
000E:|    0    0    0    0    0    0    0    0    1    1    1    1    1    1    1    1
000F:|    0    0    0    0    1    1    1    1    1    1    1    1    0    0    0    0
0010:|    1    1    1    1    1    1    1    1    0    0    0    0    0    0    0    0
0011:|    1    1    1    0    0    0    0    0    0    0    0    0    0    0    0    0
0012:|    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
0013:|    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
0014:|    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
0015:|    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
0016:|    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
0017:|    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
0018:|    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
0019:|    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
001A:|    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
001B:|    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
001C:|    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
001D:|    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
001E:|    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
001F:|    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
rank 0 coarse = 16
rank 0 fine = 32
B:|    0    0    0    0    0    0    0    0    1    1    1    0    0    0    0    0
opt_dle value:9
DRAMC_R0DELDLY[018]=00001B1C
==================================================================
                RX      DQS perbit delay software calibration 
==================================================================
1.0-15 bit dq delay value
==================================================================
bit|     0  1  2  3  4  5  6  7  8  9
--------------------------------------
0 |    10 8 10 11 11 7 11 8 8 9 
10 |    9 12 7 10 9 11 
--------------------------------------

==================================================================
2.dqs window
x=pass dqs delay value (min~max)center 
y=0-7bit DQ of every group
input delay:DQS0 =28 DQS1 = 27
==================================================================
bit     DQS0     bit      DQS1
0  (1~53)27  8  (1~53)27
1  (1~52)26  9  (1~49)25
2  (1~53)27  10  (1~53)27
3  (1~55)28  11  (1~52)26
4  (1~54)27  12  (1~53)27
5  (0~53)26  13  (1~51)26
6  (1~52)26  14  (1~52)26
7  (1~52)26  15  (1~53)27
==================================================================
3.dq delay value last
==================================================================
bit|    0  1  2  3  4  5  6  7  8   9
--------------------------------------
0 |    11 10 11 11 12 9 13 10 8 11 
10 |    9 13 7 11 10 11 
==================================================================
==================================================================
     TX  perbyte calibration 
==================================================================
DQS loop = 15, cmp_err_1 = ffff0800 
dqs_perbyte_dly.last_dqsdly_pass[0]=15,  finish count=1 
DQS loop = 14, cmp_err_1 = ffff0000 
dqs_perbyte_dly.last_dqsdly_pass[1]=14,  finish count=2 
DQ loop=15, cmp_err_1 = ffff01aa
DQ loop=14, cmp_err_1 = ffff0080
dqs_perbyte_dly.last_dqdly_pass[1]=14,  finish count=1 
DQ loop=13, cmp_err_1 = ffff0000
dqs_perbyte_dly.last_dqdly_pass[0]=13,  finish count=2 
byte:0, (DQS,DQ)=(9,8)
byte:1, (DQS,DQ)=(8,8)
20,data:89
[EMI] DRAMC calibration passed

===================================================================
                MT7621   stage1 code done 
                CPU=50000000 HZ BUS=16666666 HZ
===================================================================


U-Boot 1.1.3 (Aug 30 2017 - 02:28:33)

Board: Ralink APSoC DRAM:  256 MB
relocate_code Pointer at: 8ffb0000

Config XHCI 40M PLL 
Allocate 16 byte aligned buffer: 8ffe1940
Enable NFI Clock
# MTK NAND # : Use HW ECC
NAND ID [C2 DA 90 95 06]
Device found in MTK table, ID: c2da, EXT_ID: 909506
Support this Device in MTK table! c2da 
select_chip
[NAND]select ecc bit:4, sparesize :64 spare_per_sector=16
Signature matched and data read!
load_fact_bbt success 2047
load fact bbt success
[mtk_nand] probe successfully!
mtd->writesize=2048 mtd->oobsize=64,    mtd->erasesize=131072  devinfo.iowidth=8
..
UBNT e51 13-02122-14 B4FBE4B3E6EE
UBNT BD type=e51, mac=B4FBE4B3E6EE, s/n=B4FBE4B3E6EE, mrev=14, k_idx=1
============================================ 
Ralink UBoot Version: 4.3.S.0
-------------------------------------------- 
ASIC MT7621A DualCore (MAC to MT7530 Mode)
DRAM_CONF_FROM: Auto-Detection 
DRAM_TYPE: DDR3 
DRAM bus: 16 bit
Xtal Mode=3 OCP Ratio=1/3
Flash component: NAND Flash
Date:Aug 30 2017  Time:02:28:33
============================================ 
icache: sets:256, ways:4, linesz:32 ,total:32768
dcache: sets:256, ways:4, linesz:32 ,total:32768 

 ##### The CPU freq = 880 MHZ #### 
 estimate memory size =256 Mbytes
#Reset_MT7530
Enable port 0

Please choose the operation: 
   1: Load system code to SDRAM via TFTP. 
   2: Load system code then write to Flash via TFTP. 
   3: Boot system code via Flash (default).
   4: Entr boot command line interface.
   7: Load Boot Loader code then write to Flash via Serial. 
   9: Load Boot Loader code then write to Flash via TFTP. 
default: 3
 3 
You choosed 3

 0 
   
3: System Boot system code via Flash.
## Booting image at c0040000 ...
   Image Name:   MIPS OpenWrt Linux-5.4.48
   Image Type:   MIPS Linux Kernel Image (uncompressed)
   Data Size:    2435865 Bytes =  2.3 MB
   Load Address: 80001000
   Entry Point:  80001000
......................................   Verifying Checksum ... OK
OK
No initrd
## Transferring control to Linux (at address 80001000) ...
## Giving linux memsize in MB, 256

Starting kernel ...



OpenWrt kernel loader for MIPS based SoC
Copyright (C) 2011 Gabor Juhos <juhosg@openwrt.org>
Decompressing kernel... done!
Starting kernel at 80001000...

[    0.000000] Linux version 5.4.48 (builder@buildhost) (gcc version 8.4.0 (OpenWrt GCC 8.4.0 r13649-b1d5ab1a69)) #0 SMP Fri Jun 26 22:33:29 2020
[    0.000000] SoC Type: MediaTek MT7621 ver:1 eco:3
[    0.000000] printk: bootconsole [early0] enabled
[    0.000000] CPU0 revision is: 0001992f (MIPS 1004Kc)
[    0.000000] MIPS: machine is Ubiquiti EdgeRouter X SFP
[    0.000000] Initrd not found or empty - disabling initrd
[    0.000000] VPE topology {2,2} total 4
[    0.000000] Primary instruction cache 32kB, VIPT, 4-way, linesize 32 bytes.
[    0.000000] Primary data cache 32kB, 4-way, PIPT, no aliases, linesize 32 bytes
[    0.000000] MIPS secondary cache 256kB, 8-way, linesize 32 bytes.
[    0.000000] Zone ranges:
[    0.000000]   Normal   [mem 0x0000000000000000-0x000000000fffffff]
[    0.000000]   HighMem  empty
[    0.000000] Movable zone start for each node
[    0.000000] Early memory node ranges
[    0.000000]   node   0: [mem 0x0000000000000000-0x000000000fffffff]
[    0.000000] Initmem setup node 0 [mem 0x0000000000000000-0x000000000fffffff]
[    0.000000] percpu: Embedded 14 pages/cpu s26704 r8192 d22448 u57344
[    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 64960
[    0.000000] Kernel command line: console=ttyS0,57600 rootfstype=squashfs,jffs2
[    0.000000] Dentry cache hash table entries: 32768 (order: 5, 131072 bytes, linear)
[    0.000000] Inode-cache hash table entries: 16384 (order: 4, 65536 bytes, linear)
[    0.000000] Writing ErrCtl register=00032940
[    0.000000] Readback ErrCtl register=00032940
[    0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off
[    0.000000] Memory: 250536K/262144K available (5846K kernel code, 201K rwdata, 1260K rodata, 1256K init, 237K bss, 11608K reserved, 0K cma-reserved, 0K highmem)
[    0.000000] SLUB: HWalign=32, Order=0-3, MinObjects=0, CPUs=4, Nodes=1
[    0.000000] rcu: Hierarchical RCU implementation.
[    0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 25 jiffies.
[    0.000000] NR_IRQS: 256
[    0.000000] random: get_random_bytes called from start_kernel+0x340/0x558 with crng_init=0
[    0.000000] CPU Clock: 880MHz
[    0.000000] clocksource: GIC: mask: 0xffffffffffffffff max_cycles: 0xcaf478abb4, max_idle_ns: 440795247997 ns
[    0.000000] clocksource: MIPS: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 4343773742 ns
[    0.000009] sched_clock: 32 bits at 440MHz, resolution 2ns, wraps every 4880645118ns
[    0.015483] Calibrating delay loop... 583.68 BogoMIPS (lpj=1167360)
[    0.055830] pid_max: default: 32768 minimum: 301
[    0.065180] Mount-cache hash table entries: 1024 (order: 0, 4096 bytes, linear)
[    0.079586] Mountpoint-cache hash table entries: 1024 (order: 0, 4096 bytes, linear)
[    0.097702] rcu: Hierarchical SRCU implementation.
[    0.107813] smp: Bringing up secondary CPUs ...
[    4.135874] Primary instruction cache 32kB, VIPT, 4-way, linesize 32 bytes.
[    4.135885] Primary data cache 32kB, 4-way, PIPT, no aliases, linesize 32 bytes
[    4.135897] MIPS secondary cache 256kB, 8-way, linesize 32 bytes.
[    4.135995] CPU1 revision is: 0001992f (MIPS 1004Kc)
[    0.144999] Synchronize counters for CPU 1: done.
[    4.226937] Primary instruction cache 32kB, VIPT, 4-way, linesize 32 bytes.
[    4.226945] Primary data cache 32kB, 4-way, PIPT, no aliases, linesize 32 bytes
[    4.226952] MIPS secondary cache 256kB, 8-way, linesize 32 bytes.
[    4.227006] CPU2 revision is: 0001992f (MIPS 1004Kc)
[    0.239460] Synchronize counters for CPU 2: done.
[    4.318055] Primary instruction cache 32kB, VIPT, 4-way, linesize 32 bytes.
[    4.318064] Primary data cache 32kB, 4-way, PIPT, no aliases, linesize 32 bytes
[    4.318072] MIPS secondary cache 256kB, 8-way, linesize 32 bytes.
[    4.318129] CPU3 revision is: 0001992f (MIPS 1004Kc)
[    0.327061] Synchronize counters for CPU 3: done.
[    0.386664] smp: Brought up 1 node, 4 CPUs
[    0.398972] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns
[    0.418237] futex hash table entries: 1024 (order: 3, 32768 bytes, linear)
[    0.432169] pinctrl core: initialized pinctrl subsystem
[    0.443530] NET: Registered protocol family 16
[    0.481661] clocksource: Switched to clocksource GIC
[    0.493356] NET: Registered protocol family 2
[    0.502975] tcp_listen_portaddr_hash hash table entries: 512 (order: 0, 6144 bytes, linear)
[    0.519574] TCP established hash table entries: 2048 (order: 1, 8192 bytes, linear)
[    0.534699] TCP bind hash table entries: 2048 (order: 2, 16384 bytes, linear)
[    0.548872] TCP: Hash tables configured (established 2048 bind 2048)
[    0.561648] UDP hash table entries: 256 (order: 1, 8192 bytes, linear)
[    0.574529] UDP-Lite hash table entries: 256 (order: 1, 8192 bytes, linear)
[    0.588595] NET: Registered protocol family 1
[    0.597152] PCI: CLS 0 bytes, default 32
[    0.693612] 4 CPUs re-calibrate udelay(lpj = 1167360)
[    0.705093] workingset: timestamp_bits=14 max_order=16 bucket_order=2
[    0.719864] random: fast init done
[    0.725746] squashfs: version 4.0 (2009/01/31) Phillip Lougher
[    0.738153] jffs2: version 2.2 (NAND) (SUMMARY) (LZMA) (RTIME) (CMODE_PRIORITY) (c) 2001-2006 Red Hat, Inc.
[    0.760502] GPIO line 487 (sfp_i2c_clk_gate) hogged as output/high
[    0.772946] mt7621_gpio 1e000600.gpio: registering 32 gpios
[    0.784177] mt7621_gpio 1e000600.gpio: registering 32 gpios
[    0.795396] mt7621_gpio 1e000600.gpio: registering 32 gpios
[    0.807068] Serial: 8250/16550 driver, 16 ports, IRQ sharing enabled
[    0.822849] printk: console [ttyS0] disabled
[    0.831301] 1e000c00.uartlite: ttyS0 at MMIO 0x1e000c00 (irq = 19, base_baud = 3125000) is a 16550A
[    0.849226] printk: console [ttyS0] enabled
[    0.849226] printk: console [ttyS0] enabled
[    0.865790] printk: bootconsole [early0] disabled
[    0.865790] printk: bootconsole [early0] disabled
[    0.886838] mt7621-nand 1e003000.nand: Using programmed access timing: 31c07388
[    0.901809] nand: device found, Manufacturer ID: 0xc2, Chip ID: 0xda
[    0.914464] nand: Macronix MX30LF2G18AC
[    0.922100] nand: 256 MiB, SLC, erase size: 128 KiB, page size: 2048, OOB size: 64
[    0.937174] mt7621-nand 1e003000.nand: ECC strength adjusted to 4 bits
[    0.950207] mt7621-nand 1e003000.nand: Using programmed access timing: 21005134
[    0.964763] mt7621-nand 1e003000.nand: Using programmed access timing: 21005134
[    0.979322] Scanning device for bad blocks
[    2.388364] Bad eraseblock 1105 at 0x000008a20000
[    3.591347] 6 fixed-partitions partitions found on MTD device mt7621-nand
[    3.604863] Creating 6 MTD partitions on "mt7621-nand":
[    3.615275] 0x000000000000-0x000000080000 : "u-boot"
[    3.626464] 0x000000080000-0x0000000e0000 : "u-boot-env"
[    3.638343] 0x0000000e0000-0x000000140000 : "factory"
[    3.649566] 0x000000140000-0x000000440000 : "kernel1"
[    3.660834] 0x000000440000-0x000000740000 : "kernel2"
[    3.672135] 0x000000740000-0x00000ff00000 : "ubi"
[    3.684934] libphy: Fixed MDIO Bus: probed
[    3.720110] libphy: mdio: probed
[    3.726777] mt7530 mdio-bus:1f: MT7530 adapts as multi-chip module
[    3.741399] mtk_soc_eth 1e100000.ethernet dsa: mediatek frame engine at 0xbe100000, irq 20
[    3.759062] i2c-mt7621 1e000900.i2c: clock 100 kHz
[    3.772209] NET: Registered protocol family 10
[    3.782778] Segment Routing with IPv6
[    3.790195] NET: Registered protocol family 17
[    3.799123] bridge: filtering via arp/ip/ip6tables is no longer available by default. Update your scripts to load br_netfilter if you need this.
[    3.825176] 8021q: 802.1Q VLAN Support v1.8
[    3.835469] mt7530 mdio-bus:1f: MT7530 adapts as multi-chip module
[    3.858806] libphy: dsa slave smi: probed
[    3.867214] mt7530 mdio-bus:1f eth0 (uninitialized): PHY [dsa-0.0:00] driver [Generic PHY]
[    3.885166] mt7530 mdio-bus:1f eth1 (uninitialized): PHY [dsa-0.0:01] driver [Generic PHY]
[    3.903046] mt7530 mdio-bus:1f eth2 (uninitialized): PHY [dsa-0.0:02] driver [Generic PHY]
[    3.920926] mt7530 mdio-bus:1f eth3 (uninitialized): PHY [dsa-0.0:03] driver [Generic PHY]
[    3.938853] mt7530 mdio-bus:1f eth4 (uninitialized): PHY [dsa-0.0:04] driver [Generic PHY]
[    3.956767] mt7530 mdio-bus:1f eth5 (uninitialized): PHY [mdio-bus:07] driver [Atheros 8031 ethernet]
[    3.976479] mt7530 mdio-bus:1f: configuring for fixed/rgmii link mode
[    3.994051] DSA: tree 0 setup
[    4.000412] mt7530 mdio-bus:1f: Link is Up - 1Gbps/Full - flow control off
[    4.001465] UBI: auto-attach mtd5
[    4.020764] ubi0: attaching mtd5
[    5.358573] ubi0 error: ubi_attach: bad image sequence number 1717396771 in PEB 1048, expected 1051561099
[    5.377643] Erase counter header dump:
[    5.385097]  magic          0x55424923
[    5.392554]  version        1
[    5.398455]  ec             0
[    5.404352]  vid_hdr_offset 2048
[    5.410778]  data_offset    4096
[    5.417194]  image_seq      1717396771
[    5.424651]  hdr_crc        0x41f68dff
[    5.432107] erase counter header hexdump:
[    5.440521] ubi0 error: ubi_attach_mtd_dev: failed to attach mtd5, error -22
[    5.454595] UBI error: cannot attach mtd5
[    5.462601] hctosys: unable to open rtc device (rtc0)
[    5.473495] /dev/root: Can't open blockdev
[    5.481701] VFS: Cannot open root device "(null)" or unknown-block(0,0): error -6
[    5.496596] Please append a correct "root=" boot option; here are the available partitions:
[    5.513231] 1f00             512 mtdblock0 
[    5.513235]  (driver?)
[    5.526248] 1f01             384 mtdblock1 
[    5.526251]  (driver?)
[    5.539271] 1f02             384 mtdblock2 
[    5.539274]  (driver?)
[    5.552283] 1f03            3072 mtdblock3 
[    5.552286]  (driver?)
[    5.565294] 1f04            3072 mtdblock4 
[    5.565298]  (driver?)
[    5.578321] 1f05          253696 mtdblock5 
[    5.578324]  (driver?)
[    5.591333] Kernel panic - not syncing: VFS: Unable to mount root fs on unknown-block(0,0)
[    5.607798] Rebooting in 1 seconds..

I've observed a few different errors on 19.07.3:

[    3.452384] UBI: auto-attach mtd5
[    3.459042] ubi0: attaching mtd5
[    5.063106] mtk_soc_eth 1e100000.ethernet eth0: port 1 link up
[    5.731856] ubi0: scanning is finished
[    5.753342] ubi0 error: 0x802f7820: bad attaching information, error 1
[    5.766336] Volume attaching information dump:
[    5.775176]  vol_id         0
[    5.781076]  highest_lnum   526
[    5.787307]  leb_count      15
[    5.793384]  compat         0
[    5.799284]  vol_type       3
[    5.805170]  used_ebs       0
[    5.811068]  last_data_size 0
[    5.816954]  data_pad       0
[    5.818148] mtk_soc_eth 1e100000.ethernet eth0: port 1 link down
[    5.822855] Volume information dump:
[    5.841894]  vol_id          0
[    5.847953]  reserved_pebs   14
[    5.854197]  alignment       1
[    5.860273]  data_pad        0
[    5.866332]  vol_type        3
[    5.872403]  name_len        6
[    5.878461]  usable_leb_size 126976
[    5.885396]  used_ebs        14
[    5.891642]  used_bytes      1777664
[    5.898752]  last_eb_bytes   126976
[    5.905674]  corrupted       0
[    5.911746]  upd_marker      0
[    5.917805]  name            rootfs
[    5.925375] ubi0 error: 0x802fb1ec: failed to attach mtd5, error -22
[    5.938048] UBI error: cannot attach mtd5
[    3.443331] UBI: auto-attach mtd5
[    3.450022] ubi0: attaching mtd5
[    4.654666] ubi0 error: 0x80307340: bad image sequence number 1717396771 in PEB 1048, expected 1051561099
[    4.673719] Erase counter header dump:
[    4.681180]  magic          0x55424923
[    4.688623]  version        1
[    4.694526]  ec             0
[    4.700432]  vid_hdr_offset 2048
[    4.706837]  data_offset    4096
[    4.713259]  image_seq      1717396771
[    4.720720]  hdr_crc        0x41f68dff
[    4.728160] erase counter header hexdump:
[    4.736480] ubi0 error: 0x802fb1ec: failed to attach mtd5, error -22
[    4.749165] UBI error: cannot attach mtd5
@openwrt-bot
Copy link
Author

openwrt-bot commented Jun 28, 2020

whitequark:

I was able to upgrade by flashing the initramfs-kernel image and then using sysupgrade -n to switch to the squashfs image. This produced some of the same attach errors, but notably, also formatted the ubi partition such that it works afterwards. I've watched the serial terminal during previous upgrade attempts and I don't recall ever seeing it run ubiformat (which takes quite a long time, so not easy to miss).

Here is the complete log from a successful upgrade:

===================================================================
                MT7621   stage1 code 10:33:11 (ASIC)
                CPU=50000000 HZ BUS=16666666 HZ
==================================================================
Change MPLL source from XTAL to CR...
do MEMPLL setting..
MEMPLL Config : 0x11100000
3PLL mode + External loopback
=== XTAL-40Mhz === DDR-1200Mhz ===
PLL2 FB_DL: 0xf, 1/0 = 580/444 3D000000
PLL4 FB_DL: 0x14, 1/0 = 574/450 51000000
PLL3 FB_DL: 0x19, 1/0 = 640/384 65000000
do DDR setting..[00320381]
Apply DDR3 Setting...(use customer AC)
          0    8   16   24   32   40   48   56   64   72   80   88   96  104  112  120
      --------------------------------------------------------------------------------
0000:|    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
0001:|    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
0002:|    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
0003:|    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
0004:|    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
0005:|    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
0006:|    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
0007:|    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
0008:|    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
0009:|    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
000A:|    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
000B:|    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
000C:|    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
000D:|    0    0    0    0    0    0    0    0    0    0    0    0    0    1    1    1
000E:|    0    0    0    0    0    0    0    1    1    1    1    1    1    1    1    1
000F:|    0    0    0    1    1    1    1    1    1    1    1    1    0    0    0    0
0010:|    1    1    1    1    1    1    1    1    0    0    0    0    0    0    0    0
0011:|    1    1    1    0    0    0    0    0    0    0    0    0    0    0    0    0
0012:|    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
0013:|    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
0014:|    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
0015:|    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
0016:|    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
0017:|    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
0018:|    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
0019:|    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
001A:|    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
001B:|    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
001C:|    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
001D:|    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
001E:|    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
001F:|    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0    0
rank 0 coarse = 15
rank 0 fine = 56
B:|    0    0    0    0    0    0    0    0    1    1    1    0    0    0    0    0
opt_dle value:9
DRAMC_R0DELDLY[018]=00001C1C
==================================================================
                RX      DQS perbit delay software calibration 
==================================================================
1.0-15 bit dq delay value
==================================================================
bit|     0  1  2  3  4  5  6  7  8  9
--------------------------------------
0 |    10 8 10 11 11 8 11 8 8 10 
10 |    9 12 8 10 9 11 
--------------------------------------

==================================================================
2.dqs window
x=pass dqs delay value (min~max)center 
y=0-7bit DQ of every group
input delay:DQS0 =28 DQS1 = 28
==================================================================
bit     DQS0     bit      DQS1
0  (1~52)26  8  (1~52)26
1  (1~51)26  9  (1~51)26
2  (1~52)26  10  (1~54)27
3  (1~55)28  11  (1~52)26
4  (1~54)27  12  (2~54)28
5  (1~53)27  13  (0~50)25
6  (1~52)26  14  (1~52)26
7  (1~52)26  15  (1~52)26
==================================================================
3.dq delay value last
==================================================================
bit|    0  1  2  3  4  5  6  7  8   9
--------------------------------------
0 |    12 10 12 11 12 9 13 10 10 12 
10 |    10 14 8 13 11 13 
==================================================================
==================================================================
     TX  perbyte calibration 
==================================================================
DQS loop = 15, cmp_err_1 = ffff2800 
dqs_perbyte_dly.last_dqsdly_pass[0]=15,  finish count=1 
DQS loop = 14, cmp_err_1 = ffff0000 
dqs_perbyte_dly.last_dqsdly_pass[1]=14,  finish count=2 
DQ loop=15, cmp_err_1 = ffff01aa
DQ loop=14, cmp_err_1 = ffff00a2
dqs_perbyte_dly.last_dqdly_pass[1]=14,  finish count=1 
DQ loop=13, cmp_err_1 = ffff0000
dqs_perbyte_dly.last_dqdly_pass[0]=13,  finish count=2 
byte:0, (DQS,DQ)=(9,8)
byte:1, (DQS,DQ)=(8,8)
20,data:89
[EMI] DRAMC calibration passed

===================================================================
                MT7621   stage1 code done 
                CPU=50000000 HZ BUS=16666666 HZ
===================================================================


U-Boot 1.1.3 (Aug 30 2017 - 02:28:33)

Board: Ralink APSoC DRAM:  256 MB
relocate_code Pointer at: 8ffb0000

Config XHCI 40M PLL 
******************************
Software System Reset Occurred
******************************
Allocate 16 byte aligned buffer: 8ffe1940
Enable NFI Clock
# MTK NAND # : Use HW ECC
NAND ID [C2 DA 90 95 06]
Device found in MTK table, ID: c2da, EXT_ID: 909506
Support this Device in MTK table! c2da 
select_chip
[NAND]select ecc bit:4, sparesize :64 spare_per_sector=16
Signature matched and data read!
load_fact_bbt success 2047
load fact bbt success
[mtk_nand] probe successfully!
mtd->writesize=2048 mtd->oobsize=64,    mtd->erasesize=131072  devinfo.iowidth=8
..
UBNT e51 13-02122-14 B4FBE4B3E6EE
UBNT BD type=e51, mac=B4FBE4B3E6EE, s/n=B4FBE4B3E6EE, mrev=14, k_idx=1
============================================ 
Ralink UBoot Version: 4.3.S.0
-------------------------------------------- 
ASIC MT7621A DualCore (MAC to MT7530 Mode)
DRAM_CONF_FROM: Auto-Detection 
DRAM_TYPE: DDR3 
DRAM bus: 16 bit
Xtal Mode=3 OCP Ratio=1/3
Flash component: NAND Flash
Date:Aug 30 2017  Time:02:28:33
============================================ 
icache: sets:256, ways:4, linesz:32 ,total:32768
dcache: sets:256, ways:4, linesz:32 ,total:32768 

 ##### The CPU freq = 880 MHZ #### 
 estimate memory size =256 Mbytes
#Reset_MT7530
Enable port 0

Please choose the operation: 
   1: Load system code to SDRAM via TFTP. 
   2: Load system code then write to Flash via TFTP. 
   3: Boot system code via Flash (default).
   4: Entr boot command line interface.
   7: Load Boot Loader code then write to Flash via Serial. 
   9: Load Boot Loader code then write to Flash via TFTP. 
default: 3
 3 
You choosed 2

 0 

   
2: System Load Linux Kernel then write to Flash via TFTP. 
 Warning!! Erase Linux in Flash then burn new one. Are you sure?(Y/N)
 Please Input new ones /or Ctrl-C to discard
        Input device IP (172.16.3.211) ==:
        Input server IP (172.16.3.210) ==:
        Input Linux Kernel filename (vme50) ==:

 netboot_common, argc= 3 

 NetTxPacket = 0x8FFE5B80 

 KSEG1ADDR(NetTxPacket) = 0xAFFE5B80 

 NetLoop,call eth_halt ! 

 NetLoop,call eth_init ! 
Trying Eth0 (10/100-M)

 Waitting for RX_DMA_BUSY status Start... done


 ETH_STATE_ACTIVE!! 
TFTP from server 172.16.3.210; our IP address is 172.16.3.211
Filename 'vme50'.

 TIMEOUT_COUNT=10,Load address: 0x80100000
Loading: checksum bad
checksum bad
Got ARP REPLY, set server/gtwy eth addr (00:e0:4c:68:01:76)
Got it
#################################################################
         #################################################################
         #################################################################
         #################################################################
         #################################################################
         #################################################################
         #################################################################
         #################################################################
         #################################################################
         #################################################################
         ###########################################
done
Bytes transferred = 3546483 (361d73 hex)
NetBootFileXferSize= 00361d73
ranand_erase: start:140000, len:20000 
..ranand_erase: start:160000, len:20000 
..ranand_erase: start:180000, len:20000 
..ranand_erase: start:1a0000, len:20000 
..ranand_erase: start:1c0000, len:20000 
..ranand_erase: start:1e0000, len:20000 
..ranand_erase: start:200000, len:20000 
..ranand_erase: start:220000, len:20000 
..ranand_erase: start:240000, len:20000 
..ranand_erase: start:260000, len:20000 
..ranand_erase: start:280000, len:20000 
..ranand_erase: start:2a0000, len:20000 
..ranand_erase: start:2c0000, len:20000 
..ranand_erase: start:2e0000, len:20000 
..ranand_erase: start:300000, len:20000 
..ranand_erase: start:320000, len:20000 
..ranand_erase: start:340000, len:20000 
..ranand_erase: start:360000, len:20000 
..ranand_erase: start:380000, len:20000 
..ranand_erase: start:3a0000, len:20000 
..ranand_erase: start:3c0000, len:20000 
..ranand_erase: start:3e0000, len:20000 
..ranand_erase: start:400000, len:20000 
..ranand_erase: start:420000, len:20000 
..ranand_erase: start:440000, len:20000 
..ranand_erase: start:460000, len:20000 
..ranand_erase: start:480000, len:20000 
....ranand_erase: start:4a0000, len:20000 
.(5197)offs=4849664 piece=0 piece_size=7539 rc=0
Done!
## Booting image at bfd40000 ...
   Image Name:   MIPS OpenWrt Linux-4.14.180
   Image Type:   MIPS Linux Kernel Image (lzma compressed)
   Data Size:    3546419 Bytes =  3.4 MB
   Load Address: 80001000
   Entry Point:  80001000
.......................................................   Verifying Checksum ... OK
   Uncompressing Kernel Image ... OK
No initrd
## Transferring control to Linux (at address 80001000) ...
## Giving linux memsize in MB, 256

Starting kernel ...

[    0.000000] Linux version 4.14.180 (builder@buildhost) (gcc version 7.5.0 (OpenWrt GCC 7.5.0 r11063-85e04e9f46)) #0 SMP Sat May 16 18:32:20 2020
[    0.000000] SoC Type: MediaTek MT7621 ver:1 eco:3
[    0.000000] bootconsole [early0] enabled
[    0.000000] CPU0 revision is: 0001992f (MIPS 1004Kc)
[    0.000000] MIPS: machine is UBNT-ERX-SFP
[    0.000000] Determined physical RAM map:
[    0.000000]  memory: 10000000 @ 00000000 (usable)
[    0.000000] Initrd not found or empty - disabling initrd
[    0.000000] VPE topology {2,2} total 4
[    0.000000] Primary instruction cache 32kB, VIPT, 4-way, linesize 32 bytes.
[    0.000000] Primary data cache 32kB, 4-way, PIPT, no aliases, linesize 32 bytes
[    0.000000] MIPS secondary cache 256kB, 8-way, linesize 32 bytes.
[    0.000000] Zone ranges:
[    0.000000]   Normal   [mem 0x0000000000000000-0x000000000fffffff]
[    0.000000]   HighMem  empty
[    0.000000] Movable zone start for each node
[    0.000000] Early memory node ranges
[    0.000000]   node   0: [mem 0x0000000000000000-0x000000000fffffff]
[    0.000000] Initmem setup node 0 [mem 0x0000000000000000-0x000000000fffffff]
[    0.000000] random: get_random_bytes called from 0x80575744 with crng_init=0
[    0.000000] percpu: Embedded 14 pages/cpu s26224 r8192 d22928 u57344
[    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 65024
[    0.000000] Kernel command line: console=ttyS0,57600 rootfstype=squashfs,jffs2
[    0.000000] PID hash table entries: 1024 (order: 0, 4096 bytes)
[    0.000000] Dentry cache hash table entries: 32768 (order: 5, 131072 bytes)
[    0.000000] Inode-cache hash table entries: 16384 (order: 4, 65536 bytes)
[    0.000000] Writing ErrCtl register=00012940
[    0.000000] Readback ErrCtl register=00012940
[    0.000000] Memory: 250864K/262144K available (4748K kernel code, 239K rwdata, 588K rodata, 2860K init, 255K bss, 11280K reserved, 0K cma-reserved, 0K highmem)
[    0.000000] SLUB: HWalign=32, Order=0-3, MinObjects=0, CPUs=4, Nodes=1
[    0.000000] Hierarchical RCU implementation.
[    0.000000] NR_IRQS: 256
[    0.000000] CPU Clock: 880MHz
[    0.000000] clocksource: GIC: mask: 0xffffffffffffffff max_cycles: 0xcaf478abb4, max_idle_ns: 440795247997 ns
[    0.000000] clocksource: MIPS: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 4343773742 ns
[    0.000009] sched_clock: 32 bits at 440MHz, resolution 2ns, wraps every 4880645118ns
[    0.015497] Calibrating delay loop... 586.13 BogoMIPS (lpj=2930688)
[    0.087829] pid_max: default: 32768 minimum: 301
[    0.097143] Mount-cache hash table entries: 1024 (order: 0, 4096 bytes)
[    0.110164] Mountpoint-cache hash table entries: 1024 (order: 0, 4096 bytes)
[    0.125898] Hierarchical SRCU implementation.
[    0.135362] smp: Bringing up secondary CPUs ...
[    0.159836] Primary instruction cache 32kB, VIPT, 4-way, linesize 32 bytes.
[    0.159846] Primary data cache 32kB, 4-way, PIPT, no aliases, linesize 32 bytes
[    0.159858] MIPS secondary cache 256kB, 8-way, linesize 32 bytes.
[    0.159989] CPU1 revision is: 0001992f (MIPS 1004Kc)
[    0.204738] Synchronize counters for CPU 1: done.
[    0.283581] Primary instruction cache 32kB, VIPT, 4-way, linesize 32 bytes.
[    0.283589] Primary data cache 32kB, 4-way, PIPT, no aliases, linesize 32 bytes
[    0.283596] MIPS secondary cache 256kB, 8-way, linesize 32 bytes.
[    0.283665] CPU2 revision is: 0001992f (MIPS 1004Kc)
[    0.325567] Synchronize counters for CPU 2: done.
[    0.400652] Primary instruction cache 32kB, VIPT, 4-way, linesize 32 bytes.
[    0.400660] Primary data cache 32kB, 4-way, PIPT, no aliases, linesize 32 bytes
[    0.400666] MIPS secondary cache 256kB, 8-way, linesize 32 bytes.
[    0.400745] CPU3 revision is: 0001992f (MIPS 1004Kc)
[    0.445139] Synchronize counters for CPU 3: done.
[    0.504731] smp: Brought up 1 node, 4 CPUs
[    0.516353] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[    0.535821] futex hash table entries: 1024 (order: 3, 32768 bytes)
[    0.548260] pinctrl core: initialized pinctrl subsystem
[    0.559977] NET: Registered protocol family 16
[    0.583009] mt7621_gpio 1e000600.gpio: registering 32 gpios
[    0.594330] mt7621_gpio 1e000600.gpio: registering 32 gpios
[    0.605521] mt7621_gpio 1e000600.gpio: registering 32 gpios
[    0.619223] clocksource: Switched to clocksource GIC
[    0.630482] NET: Registered protocol family 2
[    0.640056] TCP established hash table entries: 2048 (order: 1, 8192 bytes)
[    0.653816] TCP bind hash table entries: 2048 (order: 2, 16384 bytes)
[    0.666597] TCP: Hash tables configured (established 2048 bind 2048)
[    0.679350] UDP hash table entries: 256 (order: 1, 8192 bytes)
[    0.690848] UDP-Lite hash table entries: 256 (order: 1, 8192 bytes)
[    0.703506] NET: Registered protocol family 1
[    2.839187] 4 CPUs re-calibrate udelay(lpj = 2924544)
[    2.850319] Crashlog allocated RAM at address 0x3f00000
[    2.860987] workingset: timestamp_bits=30 max_order=16 bucket_order=0
[    2.881139] squashfs: version 4.0 (2009/01/31) Phillip Lougher
[    2.892644] jffs2: version 2.2 (NAND) (SUMMARY) (LZMA) (RTIME) (CMODE_PRIORITY) (c) 2001-2006 Red Hat, Inc.
[    2.913286] random: fast init done
[    2.922261] io scheduler noop registered
[    2.930046] io scheduler deadline registered (default)
[    2.941133] Serial: 8250/16550 driver, 16 ports, IRQ sharing enabled
[    2.957198] console [ttyS0] disabled
[    2.964306] 1e000c00.uartlite: ttyS0 at MMIO 0x1e000c00 (irq = 19, base_baud = 3125000) is a 16550A
[    2.982198] console [ttyS0] enabled
[    2.982198] console [ttyS0] enabled
[    2.995990] bootconsole [early0] disabled
[    2.995990] bootconsole [early0] disabled
[    3.014092] MediaTek Nand driver init, version v2.1 Fix AHB virt2phys error
[    3.028136] Enable NFI Clock
[    3.033881] # MTK NAND # : Use HW ECC
[    3.041195] Device not found, ID: c2da
[    3.048636] Not Support this Device! 
[    3.056095] chip_mode=00000001
[    3.062182] Support this Device in MTK table! c2da 
[    3.072079] [NAND]select ecc bit:4, sparesize :64 spare_per_sector=16
[    3.084955] nand: device found, Manufacturer ID: 0xc2, Chip ID: 0xda
[    3.097602] nand: Macronix NAND 256MiB 3,3V 8-bit
[    3.106972] nand: 256 MiB, SLC, erase size: 128 KiB, page size: 2048, OOB size: 64
[    3.122063] Scanning device for bad blocks
[    3.402403] Bad eraseblock 1105 at 0x000008a20000
[    3.643712] 6 fixed-partitions partitions found on MTD device MT7621-NAND
[    3.657225] Creating 6 MTD partitions on "MT7621-NAND":
[    3.667638] 0x000000000000-0x000000080000 : "u-boot"
[    3.678618] 0x000000080000-0x0000000e0000 : "u-boot-env"
[    3.690254] 0x0000000e0000-0x000000140000 : "factory"
[    3.701368] 0x000000140000-0x000000440000 : "kernel1"
[    3.712479] 0x000000440000-0x000000740000 : "kernel2"
[    3.723579] 0x000000740000-0x00000ff00000 : "ubi"
[    3.735902] [mtk_nand] probe successfully!
[    3.744788] Signature matched and data read!
[    3.753291] load_fact_bbt success 2047
[    3.761517] libphy: Fixed MDIO Bus: probed
[    3.841773] libphy: mdio: probed
[    5.257798] mtk_soc_eth 1e100000.ethernet: loaded mt7530 driver
[    5.270383] mtk_soc_eth 1e100000.ethernet eth0: mediatek frame engine at 0xbe100000, irq 20
[    5.289416] NET: Registered protocol family 10
[    5.299838] Segment Routing with IPv6
[    5.307199] NET: Registered protocol family 17
[    5.316123] bridge: filtering via arp/ip/ip6tables is no longer available by default. Update your scripts to load br_netfilter if you need this.
[    5.341917] 8021q: 802.1Q VLAN Support v1.8
[    5.352960] UBI: auto-attach mtd5
[    5.359669] ubi0: attaching mtd5
[    6.564256] ubi0 error: 0x80307340: bad image sequence number 1717396771 in PEB 1048, expected 1051561099
[    6.583307] Erase counter header dump:
[    6.590764]  magic          0x55424923
[    6.598207]  version        1
[    6.604105]  ec             0
[    6.610006]  vid_hdr_offset 2048
[    6.616409]  data_offset    4096
[    6.622827]  image_seq      1717396771
[    6.630283]  hdr_crc        0x41f68dff
[    6.637725] erase counter header hexdump:
[    6.646041] ubi0 error: 0x802fb1ec: failed to attach mtd5, error -22
[    6.658717] UBI error: cannot attach mtd5
[    6.666723] hctosys: unable to open rtc device (rtc0)
[    6.687451] Freeing unused kernel memory: 2860K
[    6.696493] This architecture does not have kernel memory protection.
[    6.720885] init: Console is alive
[    6.727883] init: - watchdog -
[    6.744454] kmodloader: loading kernel modules from /etc/modules-boot.d/*
[    6.760973] kmodloader: done loading kernel modules from /etc/modules-boot.d/*
[    6.789527] init: - preinit -
[    6.934778] mtk_soc_eth 1e100000.ethernet: PPE started
[    6.943016] mtk_soc_eth 1e100000.ethernet eth0: port 0 link up
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

[   10.071724] mtk_soc_eth 1e100000.ethernet: 0x100 = 0x6060000c, 0x10c = 0x80818
[   10.093066] procd: - early -
[   10.098896] procd: - watchdog -
[   10.719357] procd: - watchdog -
[   10.725950] procd: - ubus -
[   10.736306] random: ubusd: uninitialized urandom read (4 bytes read)
[   10.789785] random: ubusd: uninitialized urandom read (4 bytes read)
[   10.802813] random: ubusd: uninitialized urandom read (4 bytes read)
[   10.816326] procd: - init -
Please press Enter to activate this console.
[   11.048146] kmodloader: loading kernel modules from /etc/modules.d/*
[   11.064520] ip6_tables: (C) 2000-2006 Netfilter Core Team
[   11.080800] ip_tables: (C) 2000-2006 Netfilter Core Team
[   11.097155] nf_conntrack version 0.5.0 (4096 buckets, 16384 max)
[   11.141827] xt_time: kernel timezone is -0000
[   11.155732] PPP generic driver version 2.4.2
[   11.165447] NET: Registered protocol family 24
[   11.176420] kmodloader: done loading kernel modules from /etc/modules.d/*
[   11.234850] urngd: v1.0.2 started.
[   11.372886] random: crng init done
[   11.379662] random: 7 urandom warning(s) missed due to ratelimiting



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

  _______                     ________        __
 |       |.-----.-----.-----.|  |  |  |.----.|  |_
 |   -   ||  _  |  -__|     ||  |  |  ||   _||   _|
 |_______||   __|_____|__|__||________||__|  |____|
          |__| W I R E L E S S   F R E E D O M
 -----------------------------------------------------
 OpenWrt 19.07.3, r11063-85e04e9f46
 -----------------------------------------------------
=== WARNING! =====================================
There is no root password defined on this device!
Use the "passwd" command to set up a new password
in order to prevent unauthorized SSH logins.
--------------------------------------------------
root@(none):/# [   19.411888] mtk_soc_eth 1e100000.ethernet: PPE started
[   19.428689] br-lan: port 1(eth0.1) entered blocking state
[   19.439532] br-lan: port 1(eth0.1) entered disabled state
[   19.451227] device eth0.1 entered promiscuous mode
[   19.460848] device eth0 entered promiscuous mode
[   19.473815] br-lan: port 1(eth0.1) entered blocking state
[   19.484638] br-lan: port 1(eth0.1) entered forwarding state
[   19.496356] IPv6: ADDRCONF(NETDEV_UP): br-lan: link is not ready
[   20.429821] IPv6: ADDRCONF(NETDEV_CHANGE): br-lan: link becomes ready
[   20.642154] export_store: invalid GPIO 496
[   21.661501] export_store: invalid GPIO 497
[   22.681377] export_store: invalid GPIO 498
[   23.124382] mtk_soc_eth 1e100000.ethernet eth0: port 0 link down
[   23.701350] export_store: invalid GPIO 499
[   24.721300] export_store: invalid GPIO 500
[   25.797385] mtk_soc_eth 1e100000.ethernet eth0: port 1 link up

root@OpenWrt:/# ls
bin      etc      lib      overlay  rom      sbin     tmp      var
dev      init     mnt      proc     root     sys      usr      www
root@OpenWrt:/# cd
root@OpenWrt:~# ls
openwrt-19.07.3-ramips-mt7621-ubnt-erx-sfp-squashfs-sysupgrade.bin
root@OpenWrt:~# mv openwrt-19.07.3-ramips-mt7621-ubnt-erx-sfp-squashfs-sysupgrad
e.bin /tmp
root@OpenWrt:~# cd /tmp
root@OpenWrt:/tmp# ls
TZ
dhcp.leases
dnsmasq.d
etc
hosts
lib
lock
log
luci-indexcache
luci-indexcache.tZq3JROs.ZFQ6ZsJLsUCD..json
luci-modulecache
openwrt-19.07.3-ramips-mt7621-ubnt-erx-sfp-squashfs-sysupgrade.bin
resolv.conf
resolv.conf.auto
run
shm
state
sysinfo
tmp
root@OpenWrt:/tmp# sysupgrade -n openwrt-19.07.3-ramips-mt7621-ubnt-erx-sfp-squa
shfs-sysupgrade.bin 
Commencing upgrade. Closing all shell sessions.
Watchdog handover: fd=3
- watchdog -
killall: telnetd: no process killed
Sending TERM to remaining processes ... odhcpd uhttpd udhcpc odhcp6c dnsmasq ntpd ubusd urngd logd rpcd netifd 
Sending KILL to remaining processes ... ntpd 
Performing system upgrade...
[   60.825926] ubi0: attaching mtd5
[   62.031299] ubi0 error: 0x80307340: bad image sequence number 1717396771 in PEB 1048, expected 1051561099
[   62.050346] Erase counter header dump:
[   62.057789]  magic          0x55424923
[   62.065244]  version        1
[   62.071145]  ec             0
[   62.077031]  vid_hdr_offset 2048
[   62.083448]  data_offset    4096
[   62.089872]  image_seq      1717396771
[   62.097314]  hdr_crc        0x41f68dff
[   62.104766] erase counter header hexdump:
[   62.113117] ubi0 error: 0x802fb1ec: failed to attach mtd5, error -22
ubiattach: error!: cannot attach mtd5
           error 22 (Invalid argument)
1+0 records in
1+0 records out
Unlocking kernel1 ...

Writing from <stdin> to kernel1 ...     
[   63.591183] ubi0: attaching mtd5
[   64.796502] ubi0 error: 0x80307340: bad image sequence number 1717396771 in PEB 1048, expected 1051561099
[   64.815552] Erase counter header dump:
[   64.823010]  magic          0x55424923
[   64.830466]  version        1
[   64.836352]  ec             0
[   64.842251]  vid_hdr_offset 2048
[   64.848656]  data_offset    4096
[   64.855072]  image_seq      1717396771
[   64.862528]  hdr_crc        0x41f68dff
[   64.869987] erase counter header hexdump:
[   64.878295] ubi0 error: 0x802fb1ec: failed to attach mtd5, error -22
ubiattach: error!: cannot attach mtd5
           error 22 (Invalid argument)
ubiformat: mtd5 (nand), size 259784704 bytes (247.7 MiB), 1982 eraseblocks of 131072 bytes (128.0 KiB), min. I/O size 2048 bytes
libscan: scanning eraseblock 1981 -- 100 % complete  
ubiformat: 1981 eraseblocks have valid erase counter, mean value is 1
ubiformat: 1 bad eraseblocks found, numbers: 1047
ubiformat: formatting eraseblock 1969 -- 99 %[  102.122059] ubi0: attaching mtd5
ubiformat: formatting eraseblock 1981 -- 100 % complete  
[  104.397355] ubi0: scanning is finished
[  104.421840] ubi0: attached mtd5 (name "ubi", size 247 MiB)
[  104.432794] ubi0: PEB size: 131072 bytes (128 KiB), LEB size: 126976 bytes
[  104.446474] ubi0: min./max. I/O unit sizes: 2048/2048, sub-page size 2048
[  104.459997] ubi0: VID header offset: 2048 (aligned 2048), data offset: 4096
[  104.473850] ubi0: good PEBs: 1981, bad PEBs: 1, corrupted PEBs: 0
[  104.485974] ubi0: user volume: 0, internal volumes: 1, max. volumes count: 128
[  104.500354] ubi0: max/mean erase counter: 3/2, WL threshold: 4096, image sequence number: 1421932651
[  104.518527] ubi0: available PEBs: 1938, total reserved PEBs: 43, PEBs reserved for bad PEB handling: 39
[  104.537248] ubi0: background thread "ubi_bgt0d" started, PID 1707
UBI device number 0, total 1981 LEBs (251539456 bytes, 239.8 MiB), available 1938 LEBs (246079488 bytes, 234.6 MiB), LEB size 126976 bytes (124.0 KiB)
Volume ID 0, size 14 LEBs (1777664 bytes, 1.6 MiB), LEB size 126976 bytes (124.0 KiB), dynamic, name "rootfs", alignment 1
Set volume size to 244301824
Volume ID 1, size 1924 LEBs (244301824 bytes, 232.9 MiB), LEB size 126976 bytes (124.0 KiB), dynamic, name "rootfs_data", alignment 1
sysupgrade successful
umount: can't unmount /dev: Resource busy
umount: can't unmount /tmp: Resource busy
umount: can't unmount /: Invalid argument
[  105.769602] reboot: Restarting system

@openwrt-bot
Copy link
Author

bjonglez:

It looks similar to FS#2713 where Petr couldn't reproduce my issue.

When you sysupgraded from 18.06, was it a 18.06 initramfs image booted to RAM, or an actual 18.06 openwrt running from the NAND?

In my case I "solved" the issue by booting the 19.07 initramfs-kernel.bin to RAM (option "1: System Load Linux to SDRAM via TFTP" in the bootloader) and then sysupgrading to the 19.07 squashfs image.

@openwrt-bot
Copy link
Author

whitequark:

When you sysupgraded from 18.06, was it a 18.06 initramfs image booted to RAM, or an actual 18.06 openwrt running from the NAND?

It was an initramfs image flashed to NAND, but without the mtd partition. So something in between? My conclusion was that it doesn't matter whether the kernel boots from RAM or NAND (not surprisingly, since it only matters to uboot), but it does matter whether there's an mtd partition.

@ynezz
Copy link
Member

ynezz commented May 23, 2022

Likely related to #9085 and as 19.07 is EOL I'm closing this.

@ynezz ynezz closed this as completed May 23, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

2 participants