[FS#510] slow sysupgrade

[LEDE Bugs]

A new Flyspray task has been opened.  Details are below. 

User who did this - psyborg55 (psyborg55) 

Attached to Project - LEDE Project
Summary - slow sysupgrade
Task Type - Bug Report
Category - Base system
Status - Unconfirmed
Assigned To - 
Operating System - All
Severity - Low
Priority - Very Low
Reported Version - All
Due in Version - Undecided
Due Date - Undecided
Details - Hi

image flashing seems to be taking too long
   
- Xiaomi Mini
- 17.01-rc1, 17.01-rc2, trunk r3377-368cc8e
- flash 17.01-rc2 then sysupgrade to 17.01-rc1 and finally sysupgrade to r3377

the device has not been reachable for almost 5 minutes (no dhcp and wifi, did not try static ip).

root at LEDE:~# dmesg
[    0.000000] Linux version 4.4.47 (buildbot at builds) (gcc version 5.4.0 (LEDE GCC 5.4.0 r3377-368cc8e) ) #0 Sun Feb 12 13:53:29 2017
[    0.000000] Board has DDR2
[    0.000000] Analog PMU set to hw control
[    0.000000] Digital PMU set to hw control
[    0.000000] SoC Type: MediaTek MT7620A ver:2 eco:6
[    0.000000] bootconsole [early0] enabled
[    0.000000] CPU0 revision is: 00019650 (MIPS 24KEc)
[    0.000000] MIPS: machine is Xiaomi MiWiFi Mini
[    0.000000] Determined physical RAM map:
[    0.000000]  memory: 08000000 @ 00000000 (usable)
[    0.000000] Initrd not found or empty - disabling initrd
[    0.000000] Zone ranges:
[    0.000000]   Normal   [mem 0x0000000000000000-0x0000000007ffffff]
[    0.000000] Movable zone start for each node
[    0.000000] Early memory node ranges
[    0.000000]   node   0: [mem 0x0000000000000000-0x0000000007ffffff]
[    0.000000] Initmem setup node 0 [mem 0x0000000000000000-0x0000000007ffffff]
[    0.000000] On node 0 totalpages: 32768
[    0.000000] free_area_init_node: node 0, pgdat 803b04b0, node_mem_map 81000000
[    0.000000]   Normal zone: 256 pages used for memmap
[    0.000000]   Normal zone: 0 pages reserved
[    0.000000]   Normal zone: 32768 pages, LIFO batch:7
[    0.000000] Primary instruction cache 64kB, VIPT, 4-way, linesize 32 bytes.
[    0.000000] Primary data cache 32kB, 4-way, PIPT, no aliases, linesize 32 bytes
[    0.000000] pcpu-alloc: s0 r0 d32768 u32768 alloc=1*32768
[    0.000000] pcpu-alloc: [0] 0 
[    0.000000] Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 32512
[    0.000000] Kernel command line: console=ttyS0,115200 rootfstype=squashfs,jffs2
[    0.000000] PID hash table entries: 512 (order: -1, 2048 bytes)
[    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] Writing ErrCtl register=0007fee0
[    0.000000] Readback ErrCtl register=0007fee0
[    0.000000] Memory: 125540K/131072K available (3020K kernel code, 144K rwdata, 720K rodata, 204K init, 208K bss, 5532K reserved, 0K cma-reserved)
[    0.000000] SLUB: HWalign=32, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
[    0.000000] NR_IRQS:256
[    0.000000] CPU Clock: 580MHz
[    0.000000] clocksource: systick: mask: 0xffff max_cycles: 0xffff, max_idle_ns: 583261500 ns
[    0.000000] systick: enable autosleep mode
[    0.000000] systick: running - mult: 214748, shift: 32
[    0.000000] clocksource: MIPS: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 6590553264 ns
[    0.000012] sched_clock: 32 bits at 290MHz, resolution 3ns, wraps every 7405115902ns
[    0.007937] Calibrating delay loop... 385.84 BogoMIPS (lpj=1929216)
[    0.070540] pid_max: default: 32768 minimum: 301
[    0.075375] Mount-cache hash table entries: 1024 (order: 0, 4096 bytes)
[    0.082041] Mountpoint-cache hash table entries: 1024 (order: 0, 4096 bytes)
[    0.095990] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[    0.106165] pinctrl core: initialized pinctrl subsystem
[    0.112730] NET: Registered protocol family 16
[    0.376330] PCI host bridge /pcie at 10140000 ranges:
[    0.381161]  MEM 0x0000000020000000..0x000000002fffffff
[    0.386455]   IO 0x0000000010160000..0x000000001016ffff
[    0.405381] rt2880_gpio 10000600.gpio: registering 24 gpios
[    0.411024] rt2880_gpio 10000600.gpio: registering 24 irq handlers
[    0.417535] rt2880_gpio 10000638.gpio: registering 16 gpios
[    0.423151] rt2880_gpio 10000638.gpio: registering 16 irq handlers
[    0.429636] rt2880_gpio 10000660.gpio: registering 32 gpios
[    0.435253] rt2880_gpio 10000660.gpio: registering 32 irq handlers
[    0.442467] PCI host bridge to bus 0000:00
[    0.446580] pci_bus 0000:00: root bus resource [mem 0x20000000-0x2fffffff]
[    0.453607] pci_bus 0000:00: root bus resource [io  0xffffffff]
[    0.459586] pci_bus 0000:00: root bus resource [??? 0x00000000 flags 0x0]
[    0.466501] pci_bus 0000:00: No busn resource found for root bus, will use [bus 00-ff]
[    0.474591] pci 0000:00:00.0: [1814:0801] type 01 class 0x060400
[    0.474639] pci 0000:00:00.0: reg 0x10: [mem 0x00000000-0x7fffffff]
[    0.474662] pci 0000:00:00.0: reg 0x14: [mem 0x20200000-0x2020ffff]
[    0.474736] pci 0000:00:00.0: supports D1
[    0.474755] pci 0000:00:00.0: PME# supported from D0 D1 D3hot
[    0.475232] pci 0000:01:00.0: [14c3:7662] type 00 class 0x028000
[    0.475305] pci 0000:01:00.0: reg 0x10: [mem 0x00000000-0x000fffff 64bit]
[    0.475368] pci 0000:01:00.0: reg 0x30: [mem 0x00000000-0x0000ffff pref]
[    0.475467] pci 0000:01:00.0: PME# supported from D0 D3hot D3cold
[    0.475721] pci_bus 0000:01: busn_res: [bus 01-ff] end is updated to 01
[    0.475750] pci_bus 0000:00: busn_res: [bus 00-ff] end is updated to 01
[    0.475804] pci 0000:00:00.0: BAR 0: no space for [mem size 0x80000000]
[    0.482519] pci 0000:00:00.0: BAR 0: failed to assign [mem size 0x80000000]
[    0.489558] pci 0000:00:00.0: BAR 8: assigned [mem 0x20000000-0x200fffff]
[    0.496475] pci 0000:00:00.0: BAR 9: assigned [mem 0x20100000-0x201fffff pref]
[    0.503811] pci 0000:00:00.0: BAR 1: assigned [mem 0x20200000-0x2020ffff]
[    0.510740] pci 0000:01:00.0: BAR 0: assigned [mem 0x20000000-0x200fffff 64bit]
[    0.518170] pci 0000:01:00.0: BAR 6: assigned [mem 0x20100000-0x2010ffff pref]
[    0.525516] pci 0000:00:00.0: PCI bridge to [bus 01]
[    0.530555] pci 0000:00:00.0:   bridge window [mem 0x20000000-0x200fffff]
[    0.537471] pci 0000:00:00.0:   bridge window [mem 0x20100000-0x201fffff pref]
[    0.544825] pci 0000:00:00.0: card - bus=0x0, slot = 0x0 irq=0
[    0.550759] pci 0000:01:00.0: card - bus=0x1, slot = 0x0 irq=4
[    0.557727] clocksource: Switched to clocksource systick
[    0.564626] NET: Registered protocol family 2
[    0.570064] TCP established hash table entries: 1024 (order: 0, 4096 bytes)
[    0.577106] TCP bind hash table entries: 1024 (order: 0, 4096 bytes)
[    0.583623] TCP: Hash tables configured (established 1024 bind 1024)
[    0.590136] UDP hash table entries: 256 (order: 0, 4096 bytes)
[    0.596026] UDP-Lite hash table entries: 256 (order: 0, 4096 bytes)
[    0.602725] NET: Registered protocol family 1
[    0.607205] PCI: CLS 80 bytes, default 32
[    0.612041] rt-timer 10000100.timer: maximum frequency is 1220Hz
[    0.619165] futex hash table entries: 256 (order: -1, 3072 bytes)
[    0.625425] Crashlog allocated RAM at address 0x3f00000
[    0.647176] squashfs: version 4.0 (2009/01/31) Phillip Lougher
[    0.653125] jffs2: version 2.2 (NAND) (SUMMARY) (LZMA) (RTIME) (CMODE_PRIORITY) (c) 2001-2006 Red Hat, Inc.
[    0.665858] io scheduler noop registered
[    0.669850] io scheduler deadline registered (default)
[    0.675275] ralink-usb-phy usbphy: invalid resource
[    0.680940] Serial: 8250/16550 driver, 16 ports, IRQ sharing enabled
[    0.691108] console [ttyS0] disabled
[    0.694715] 10000c00.uartlite: ttyS0 at MMIO 0x10000c00 (irq = 20, base_baud = 2500000) is a Palmchip BK-3103
[    0.704847] console [ttyS0] enabled
[    0.711874] bootconsole [early0] disabled
[    0.727010] spi spi0.0: force spi mode3
[    0.731557] m25p80 spi0.0: w25q128 (16384 Kbytes)
[    0.736411] 7 ofpart partitions found on MTD device spi0.0
[    0.742049] Creating 7 MTD partitions on "spi0.0":
[    0.746943] 0x000000000000-0x000000030000 : "u-boot"
[    0.753854] 0x000000030000-0x000000040000 : "u-boot-env"
[    0.761188] 0x000000040000-0x000000050000 : "factory"
[    0.768206] 0x000000050000-0x000000fd0000 : "firmware"
[    2.081066] 2 uimage-fw partitions found on MTD device firmware
[    2.087131] 0x000000050000-0x00000018fa05 : "kernel"
[    2.093835] 0x00000018fa05-0x000000fd0000 : "rootfs"
[    2.100779] mtd: device 5 (rootfs) set to be root filesystem
[    2.106705] 1 squashfs-split partitions found on MTD device rootfs
[    2.113096] 0x00000038d000-0x000000fd0000 : "rootfs_data"
[    2.120489] 0x000000fd0000-0x000000fe0000 : "crash"
[    2.127322] 0x000000fe0000-0x000000ff0000 : "reserved"
[    2.134485] 0x000000ff0000-0x000001000000 : "Bdata"
[    2.144580] gsw: setting port4 to ephy mode
[    2.148946] mtk_soc_eth 10100000.ethernet eth0 (uninitialized): port 0 link up (100Mbps/Full duplex)
[    2.158477] mtk_soc_eth 10100000.ethernet: loaded mt7620 driver
[    2.165342] mtk_soc_eth 10100000.ethernet eth0: mediatek frame engine at 0xb0100000, irq 5
[    2.174387] rt2880_wdt 10000120.watchdog: Initialized
[    2.181168] NET: Registered protocol family 10
[    2.190388] NET: Registered protocol family 17
[    2.195021] bridge: automatic filtering via arp/ip/ip6tables has been deprecated. Update your scripts to load br_netfilter if you need this.
[    2.207965] 8021q: 802.1Q VLAN Support v1.8
[    2.230354] VFS: Mounted root (squashfs filesystem) readonly on device 31:5.
[    2.238734] Freeing unused kernel memory: 204K (803cd000 - 80400000)
[    4.647687] init: Console is alive
[    4.651530] init: - watchdog -
[    6.329239] kmodloader: loading kernel modules from /etc/modules-boot.d/*
[    6.421363] usbcore: registered new interface driver usbfs
[    6.427072] usbcore: registered new interface driver hub
[    6.432679] usbcore: registered new device driver usb
[    6.443661] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[    6.452010] ehci-platform: EHCI generic platform driver
[    6.467726] phy phy-usbphy.0: remote usb device wakeup disabled
[    6.473774] phy phy-usbphy.0: UTMI 16bit 30MHz
[    6.478349] ehci-platform 101c0000.ehci: EHCI Host Controller
[    6.484245] ehci-platform 101c0000.ehci: new USB bus registered, assigned bus number 1
[    6.492460] ehci-platform 101c0000.ehci: irq 26, io mem 0x101c0000
[    6.505433] ehci-platform 101c0000.ehci: USB 2.0 started, EHCI 1.00
[    6.512963] hub 1-0:1.0: USB hub found
[    6.517238] hub 1-0:1.0: 1 port detected
[    6.524350] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
[    6.532228] ohci-platform: OHCI generic platform driver
[    6.537914] ohci-platform 101c1000.ohci: Generic Platform OHCI controller
[    6.544874] ohci-platform 101c1000.ohci: new USB bus registered, assigned bus number 2
[    6.553089] ohci-platform 101c1000.ohci: irq 26, io mem 0x101c1000
[    6.583712] hub 2-0:1.0: USB hub found
[    6.587905] hub 2-0:1.0: 1 port detected
[    6.595449] kmodloader: done loading kernel modules from /etc/modules-boot.d/*
[    6.604106] init: - preinit -
[    6.956411] usb 1-1: new high-speed USB device number 2 using ehci-platform
[    7.270746] random: procd: uninitialized urandom read (4 bytes read, 12 bits of entropy available)
[    7.640080] 8021q: adding VLAN 0 to HW filter on device eth0
[    8.529656] jffs2_scan_eraseblock(): End of filesystem marker found at 0x2000
[    8.538130] jffs2_build_filesystem(): unlocking the mtd device... done.
[    8.544910] jffs2_build_filesystem(): erasing all blocks after the end marker... 
[   78.660250] random: nonblocking pool is initialized
[  311.401301] done.
[  311.403323] jffs2: notice: (374) jffs2_build_xattr_subsystem: complete building xattr subsystem, 0 of xdatum (0 unchecked, 0 orphan) and 0 of xref (0 dead, 0 orphan) found.
[  311.421054] mount_root: overlay filesystem has not been fully initialized yet
[  311.442837] mount_root: switching to jffs2 overlay
[  311.834234] urandom-seed: Seed file not found (/etc/urandom.seed)
[  311.954212] procd: - early -
[  311.957267] procd: - watchdog -
[  312.330881] procd: - ubus -
[  312.358304] procd: - init -
[  312.624374] kmodloader: loading kernel modules from /etc/modules.d/*
[  312.637526] ip6_tables: (C) 2000-2006 Netfilter Core Team
[  312.654500] Loading modules backported from Linux version wt-2017-01-31-0-ge882dff19e7f
[  312.662749] Backport generated by backports.git backports-20160324-13-g24da7d3c
[  312.721454] mt76x2e 0000:01:00.0: ASIC revision: 76120044
[  312.734552] mt76x2e 0000:01:00.0: ROM patch already applied
[  312.741870] mt76x2e 0000:01:00.0: Firmware Version: 0.0.00
[  312.747548] mt76x2e 0000:01:00.0: Build: 1
[  312.751731] mt76x2e 0000:01:00.0: Build Time: 201507311614____
[  312.765329] mt76x2e 0000:01:00.0: Firmware running!
[  312.771221] ieee80211 phy0: Selected rate control algorithm 'minstrel_ht'
[  312.798568] ip_tables: (C) 2000-2006 Netfilter Core Team
[  312.824101] nf_conntrack version 0.5.0 (1964 buckets, 7856 max)
[  313.046235] xt_time: kernel timezone is -0000
[  313.061761] PPP generic driver version 2.4.2
[  313.069130] NET: Registered protocol family 24
[  313.091611] rt2800_wmac 10180000.wmac: loaded eeprom from mtd device "factory"
[  313.099084] ieee80211 phy1: rt2x00_set_rt: Info - RT chipset 5390, rev 0500 detected
[  313.107017] ieee80211 phy1: rt2x00_set_rf: Info - RF chipset 7620 detected
[  313.114718] ieee80211 phy1: Selected rate control algorithm 'minstrel_ht'
[  313.127635] kmodloader: done loading kernel modules from /etc/modules.d/*
[  320.473979] 8021q: adding VLAN 0 to HW filter on device eth0
[  320.498870] device eth0 entered promiscuous mode
[  320.505015] device eth0.1 entered promiscuous mode
[  320.516566] br-lan: port 1(eth0.1) entered forwarding state
[  320.522301] br-lan: port 1(eth0.1) entered forwarding state
[  322.515382] br-lan: port 1(eth0.1) entered forwarding state
[  324.129601] IPv6: ADDRCONF(NETDEV_UP): wlan1: link is not ready
[  324.149913] device wlan1 entered promiscuous mode
[  324.154799] br-lan: port 2(wlan1) entered forwarding state
[  324.160512] br-lan: port 2(wlan1) entered forwarding state
[  324.421359] IPv6: ADDRCONF(NETDEV_CHANGE): wlan1: link becomes ready
[  325.099733] br-lan: port 2(wlan1) entered forwarding state


More information can be found at the following URL:
https://bugs.lede-project.org/index.php?do=details&task_id=510