EdgeSwitch ES-5XP very slow boot

I installed OpenWRT on Ubiquiti EdgeSwitch 5XP (snapshot r26272-39f595d1d8). it works correctly but takes a very long time to finish booting, specifically with initialising interfaces. how can I fix this?

boot log below (I cannot figure out how to attach text files, only images)


U-Boot 1.1.4.2-s559 (May 23 2012 - 13:31:49)

Board: Ubiquiti Networks XM board (rev 2.4 e700)
DRAM:  64 MB
Flash:  8 MB
Net:   eth0, eth1
Hit any key to stop autoboot:  0 
## Booting image at 9f050000 ...
   Image Name:   MIPS OpenWrt Linux-6.1.89
   Created:      2024-05-09  22:11:10 UTC
   Image Type:   MIPS Linux Kernel Image (lzma compressed)
   Data Size:    2652526 Bytes =  2.5 MB
   Load Address: 80060000
   Entry Point:  80060000
   Verifying Checksum ... OK
   Uncompressing Kernel Image ... OK

Starting kernel ...

[    0.000000] Linux version 6.1.89 (builder@buildhost) (mips-openwrt-linux-musl-gcc (OpenWrt GCC 13.2.0 r26272-39f595d1d8) 13.2.0, GNU ld (GNU Binutils) 2.42) #0 Thu May  9 22:11:10 2024
[    0.000000] printk: bootconsole [early0] enabled
[    0.000000] CPU0 revision is: 00019374 (MIPS 24Kc)
[    0.000000] MIPS: machine is Ubiquiti EdgeSwitch 5XP
[    0.000000] SoC: Atheros AR7242 rev 1
[    0.000000] Initrd not found or empty - disabling initrd
[    0.000000] Primary instruction cache 64kB, VIPT, 4-way, linesize 32 bytes.
[    0.000000] Primary data cache 32kB, 4-way, VIPT, cache aliases, linesize 32 bytes
[    0.000000] Zone ranges:
[    0.000000]   Normal   [mem 0x0000000000000000-0x0000000003ffffff]
[    0.000000] Movable zone start for each node
[    0.000000] Early memory node ranges
[    0.000000]   node   0: [mem 0x0000000000000000-0x0000000003ffffff]
[    0.000000] Initmem setup node 0 [mem 0x0000000000000000-0x0000000003ffffff]
[    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 16240
[    0.000000] Kernel command line: console=ttyS0,115200n8 rootfstype=squashfs,jffs2
[    0.000000] Dentry cache hash table entries: 8192 (order: 3, 32768 bytes, linear)
[    0.000000] Inode-cache hash table entries: 4096 (order: 2, 16384 bytes, linear)
[    0.000000] Writing ErrCtl register=00000000
[    0.000000] Readback ErrCtl register=00000000
[    0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off
[    0.000000] Memory: 54816K/65536K available (6480K kernel code, 598K rwdata, 1492K rodata, 1212K init, 220K bss, 10720K reserved, 0K cma-reserved)
[    0.000000] SLUB: HWalign=32, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
[    0.000000] NR_IRQS: 51
[    0.000000] CPU clock: 390.000 MHz
[    0.000000] clocksource: MIPS: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 9801335621 ns
[    0.000002] sched_clock: 32 bits at 195MHz, resolution 5ns, wraps every 11012737021ns
[    0.007982] Calibrating delay loop... 259.27 BogoMIPS (lpj=1296384)
[    0.084144] pid_max: default: 32768 minimum: 301
[    0.090416] Mount-cache hash table entries: 1024 (order: 0, 4096 bytes, linear)
[    0.097711] Mountpoint-cache hash table entries: 1024 (order: 0, 4096 bytes, linear)
[    0.109991] cblist_init_generic: Setting adjustable number of callback queues.
[    0.117261] cblist_init_generic: Setting shift to 0 and lim to 1.
[    0.129576] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[    0.139453] futex hash table entries: 256 (order: -1, 3072 bytes, linear)
[    0.146504] pinctrl core: initialized pinctrl subsystem
[    0.154946] NET: Registered PF_NETLINK/PF_ROUTE protocol family
[    0.161872] thermal_sys: Registered thermal governor 'step_wise'
[    0.182704] clocksource: Switched to clocksource MIPS
[    0.196652] NET: Registered PF_INET protocol family
[    0.201958] IP idents hash table entries: 2048 (order: 2, 16384 bytes, linear)
[    0.211135] tcp_listen_portaddr_hash hash table entries: 1024 (order: 0, 4096 bytes, linear)
[    0.219669] Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear)
[    0.227423] TCP established hash table entries: 1024 (order: 0, 4096 bytes, linear)
[    0.235092] TCP bind hash table entries: 1024 (order: 1, 8192 bytes, linear)
[    0.242164] TCP: Hash tables configured (established 1024 bind 1024)
[    0.248820] UDP hash table entries: 256 (order: 0, 4096 bytes, linear)
[    0.255441] UDP-Lite hash table entries: 256 (order: 0, 4096 bytes, linear)
[    0.263133] NET: Registered PF_UNIX/PF_LOCAL protocol family
[    0.268857] PCI: CLS 0 bytes, default 32
[    0.278510] workingset: timestamp_bits=14 max_order=14 bucket_order=0
[    0.295804] squashfs: version 4.0 (2009/01/31) Phillip Lougher
[    0.301632] jffs2: version 2.2 (NAND) (SUMMARY) (LZMA) (RTIME) (CMODE_PRIORITY) (c) 2001-2006 Red Hat, Inc.
[    0.314049] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 251)
[    0.324604] pinctrl-single 18040028.pinmux: 64 pins, size 8
[    0.332140] Serial: 8250/16550 driver, 16 ports, IRQ sharing enabled
[    0.342984] printk: console [ttyS0] disabled
[    0.347388] 18020000.uart: ttyS0 at MMIO 0x18020000 (irq = 10, base_baud = 12187500) is a 16550A
[    0.356238] printk: console [ttyS0] enabled
[    0.356238] printk: console [ttyS0] enabled
[    0.364652] printk: bootconsole [early0] disabled
[    0.364652] printk: bootconsole [early0] disabled
[    0.403796] gpio_spi@0 enforce active low on chipselect handle
[    0.415680] spi-nor spi0.0: mx25l6405d (8192 Kbytes)
[    0.420904] 5 fixed-partitions partitions found on MTD device spi0.0
[    0.427419] OF: Bad cell count for /ahb/spi@1f000000/flash@0/partitions
[    0.434132] OF: Bad cell count for /ahb/spi@1f000000/flash@0/partitions
[    0.441173] Creating 5 MTD partitions on "spi0.0":
[    0.446059] 0x000000000000-0x000000040000 : "u-boot"
[    0.463186] 0x000000040000-0x000000050000 : "u-boot-env"
[    0.470287] 0x000000050000-0x0000007b0000 : "firmware"
[    0.480220] 2 uimage-fw partitions found on MTD device firmware
[    0.486279] Creating 2 MTD partitions on "firmware":
[    0.491274] 0x000000000000-0x000000290000 : "kernel"
[    0.497915] 0x000000290000-0x000000760000 : "rootfs"
[    0.507282] mtd: setting mtd4 (rootfs) as root device
[    0.512534] 1 squashfs-split partitions found on MTD device rootfs
[    0.518828] 0x0000005f0000-0x000000760000 : "rootfs_data"
[    0.525998] 0x0000007b0000-0x0000007f0000 : "cfg"
[    0.535077] 0x0000007f0000-0x000000800000 : "art"
[    0.541735] OF: Bad cell count for /ahb/spi@1f000000/flash@0/partitions
[    1.245206] switch0: Atheros AR8327 rev. 4 switch registered on mdio.0
[    1.900069] ag71xx 19000000.eth: connected to PHY at fixed-0:00 [uid=00000000, driver=Generic PHY]
[    1.910287] eth0: Atheros AG71xx at 0xb9000000, irq 4, mode: rgmii
[    2.255346] ag71xx 1a000000.eth: connected to PHY at fixed-0:01 [uid=00000000, driver=Generic PHY]
[    2.265587] eth1: Atheros AG71xx at 0xba000000, irq 5, mode: gmii
[    2.272481] i2c_dev: i2c /dev entries driver
[    2.280695] NET: Registered PF_INET6 protocol family
[    2.301263] Segment Routing with IPv6
[    2.305210] In-situ OAM (IOAM) with IPv6
[    2.309366] NET: Registered PF_PACKET protocol family
[    2.314583] bridge: filtering via arp/ip/ip6tables is no longer available by default. Update your scripts to load br_netfilter if you need this.
[    2.328537] 8021q: 802.1Q VLAN Support v1.8
[    2.336654] ar724x-pci 180c0000.pcie: PCIe link is down
[    2.342228] PCI host bridge to bus 0000:00
[    2.346436] pci_bus 0000:00: root bus resource [mem 0x10000000-0x13ffffff]
[    2.353371] pci_bus 0000:00: root bus resource [io  0x0000]
[    2.358972] pci_bus 0000:00: No busn resource found for root bus, will use [bus 00-ff]
[    2.368327] pci_bus 0000:00: busn_res: [bus 00-ff] end is updated to 00
[    2.377043] gpio-export gpio-export: 5 gpio(s) exported
[    2.391231] clk: Disabling unused clocks
[    2.412099] VFS: Mounted root (squashfs filesystem) readonly on device 31:4.
[    2.429224] Freeing unused kernel image (initmem) memory: 1212K
[    2.435222] This architecture does not have kernel memory protection.
[    2.441699] Run /sbin/init as init process
[    3.749763] init: Console is alive
[    3.754066] init: - watchdog -
[    3.757722] init: Watchdog has previously reset the system
[    6.204717] kmodloader: loading kernel modules from /etc/modules-boot.d/*
[    6.355408] usbcore: registered new interface driver usbfs
[    6.361041] usbcore: registered new interface driver hub
[    6.366595] usbcore: registered new device driver usb
[    6.396286] ehci-platform 1b000000.usb: EHCI Host Controller
[    6.402039] ehci-platform 1b000000.usb: new USB bus registered, assigned bus number 1
[    6.410223] ehci-platform 1b000000.usb: irq 3, io mem 0x1b000000
[    6.442757] ehci-platform 1b000000.usb: USB 2.0 started, EHCI 1.00
[    6.450583] hub 1-0:1.0: USB hub found
[    6.455759] hub 1-0:1.0: 1 port detected
[    6.476734] kmodloader: done loading kernel modules from /etc/modules-boot.d/*
[    6.494930] init: - preinit -
[   11.492737] random: crng init done
[   14.252878] eth0: link up (1000Mbps/Full duplex)
[   14.259790] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
[   14.275550] IPv6: ADDRCONF(NETDEV_CHANGE): eth0.1: link becomes ready
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
[   16.811613] jffs2: notice: (413) jffs2_build_xattr_subsystem: complete building xattr subsystem, 25 of xdatum (19 unchecked, 4 orphan) and 31 of xref (4 dead, 0 orphan) found.
[   16.834151] mount_root: switching to jffs2 overlay
[   16.843802] overlayfs: upper fs does not support tmpfile.
[   16.867534] urandom-seed: Seeding with /etc/urandom.seed
[   16.992969] eth0: link down
[   17.041572] procd: - early -
[   17.045199] procd: - watchdog -
[   17.048902] procd: Watchdog has previously reset the system
[   17.899347] procd: - watchdog -
[   17.912868] procd: Watchdog has previously reset the system
[   17.921031] procd: - ubus -
[   18.310096] procd: - init -
Please press Enter to activate this console.
[   21.532872] kmodloader: loading kernel modules from /etc/modules.d/*
[   23.107142] Loading modules backported from Linux version v6.6.15-0-g51f354b815c4
[   23.114756] Backport generated by backports.git 193becf2
[   24.240289] PPP generic driver version 2.4.2
[   24.264440] NET: Registered PF_PPPOX protocol family
[   24.396185] kmodloader: done loading kernel modules from /etc/modules.d/*
[   27.698625] urngd: v1.0.2 started.
[   57.126459] eth0: link up (1000Mbps/Full duplex)
[   57.131162] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
[   57.163868] br-lan: port 1(eth0.1) entered blocking state
[   57.169334] br-lan: port 1(eth0.1) entered disabled state
[   57.175327] device eth0.1 entered promiscuous mode
[   57.180164] device eth0 entered promiscuous mode
[   57.233035] br-lan: port 1(eth0.1) entered blocking state
[   57.238506] br-lan: port 1(eth0.1) entered forwarding state
[   57.379737] eth1: link up (1000Mbps/Full duplex)
[   57.423387] IPv6: ADDRCONF(NETDEV_CHANGE): eth1: link becomes ready
[   58.172906] IPv6: ADDRCONF(NETDEV_CHANGE): br-lan: link becomes ready

considering it's a 8/64 device, I'm surprised it even booted... :wink:

tbf that page does say it's "enough for basic usage" :smile: I'm just using openwrt to configure the hardware because vendor central management is a pain, the CPU is doing nothing 99% of the time. would be nice to quickly configure the hardware at boot :​)

maybe when I have more budget I'll get a ZyXEL GS1900-10HP haha, that is listed as 16/128... and actually has af/at PoE.

There are two things I don't expect to be the issue, but which are easy to test first, so I'd start there (but they will involve a factory reset).

The last two things before the gap are:

  • urngd
    this could be disabled (/etc/init.d/urngd disable?) without real ill-effects, so give that a try
  • kmodloader
    for ath79 everything strictly required to get wired network access is built-in, so the kmods are -kind of- optional, removing all of them (rm /etc/modules.d/*) would be an interesting test

As mentioned, I don't expect either of these to be the issue, so if they aren't firstboot to reset your device to defaults.

As you see in your log, it takes 30s for the wired network to initialize and detect a link beat, this is a rather long time - if it were a general issue on ath79, I would expect according reports (but there are none), so there must be something specific to your device. This could be caused by the installed packages (if you use the imagebuilder(s) or asu), e.g. by pulling into ag71xx and qca8k (details, ignore this), so make sure to flash a new unmodified OpenWrt image for testing. Another this to consider, these devices are about a decade old by now… hardware failure isn't that unlikely, especially dying capacitors can cause issues like the above.

Yes, this device is low-end and declared to be on the brink of EoS, but it shouldn't be that bad, yet (and without included wireless hardware, quite a bit less CPU/ RAM is needed, so the issue is less pressing for this hardware).

Test-flashing various versions (older and newer/ snapshots) of OpenWrt might also be interesting, if it shows the same behaviour with a previously known-good version, this would strong hint at hardware degradation. This is obviously only for testing, security reasons would mandate to use 23.05+ in production.

thanks for the reply. I made the two changes you mentioned, and it still takes the same 30s to initialise the link (with some speedup because it's not loading RNG / modules). the image is just latest snapshot at the time I flashed it, with the only custom config being DHCP addressing instead of the default static.

just for testing now, I also disabled a few services (dnsmasq/wpad, not sure why they were running in the first place) and set a static IP rather than DHCP, and this all got the total boot to link up time to ~47s... but I don't think this shaving off random seconds here and there is particularly useful. I'll try flashing some older versions later today/next week and assume hardware issues if it still happens there.

new boot log (taken from logread this time rather than serial console)

root@OpenWrt:~# logread
Sun May 12 06:14:11 2024 kern.notice kernel: [    0.000000] Linux version 6.1.89 (builder@buildhost) (mips-openwrt-linux-musl-gcc (OpenWrt GCC 13.2.0 r26272-39f595d1d8) 13.2.0, GNU ld (GNU Binutils) 2.42) #0 Thu May  9 22:11:10 2024
Sun May 12 06:14:11 2024 kern.info kernel: [    0.000000] printk: bootconsole [early0] enabled
Sun May 12 06:14:11 2024 kern.info kernel: [    0.000000] CPU0 revision is: 00019374 (MIPS 24Kc)
Sun May 12 06:14:11 2024 kern.info kernel: [    0.000000] MIPS: machine is Ubiquiti EdgeSwitch 5XP
Sun May 12 06:14:11 2024 kern.info kernel: [    0.000000] SoC: Atheros AR7242 rev 1
Sun May 12 06:14:11 2024 kern.info kernel: [    0.000000] Initrd not found or empty - disabling initrd
Sun May 12 06:14:11 2024 kern.info kernel: [    0.000000] Primary instruction cache 64kB, VIPT, 4-way, linesize 32 bytes.
Sun May 12 06:14:11 2024 kern.info kernel: [    0.000000] Primary data cache 32kB, 4-way, VIPT, cache aliases, linesize 32 bytes
Sun May 12 06:14:11 2024 kern.info kernel: [    0.000000] Zone ranges:
Sun May 12 06:14:11 2024 kern.info kernel: [    0.000000]   Normal   [mem 0x0000000000000000-0x0000000003ffffff]
Sun May 12 06:14:11 2024 kern.info kernel: [    0.000000] Movable zone start for each node
Sun May 12 06:14:11 2024 kern.info kernel: [    0.000000] Early memory node ranges
Sun May 12 06:14:11 2024 kern.info kernel: [    0.000000]   node   0: [mem 0x0000000000000000-0x0000000003ffffff]
Sun May 12 06:14:11 2024 kern.info kernel: [    0.000000] Initmem setup node 0 [mem 0x0000000000000000-0x0000000003ffffff]
Sun May 12 06:14:11 2024 kern.debug kernel: [    0.000000] pcpu-alloc: s0 r0 d32768 u32768 alloc=1*32768
Sun May 12 06:14:11 2024 kern.debug kernel: [    0.000000] pcpu-alloc: [0] 0
Sun May 12 06:14:11 2024 kern.info kernel: [    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 16240
Sun May 12 06:14:11 2024 kern.notice kernel: [    0.000000] Kernel command line: console=ttyS0,115200n8 rootfstype=squashfs,jffs2
Sun May 12 06:14:11 2024 kern.info kernel: [    0.000000] Dentry cache hash table entries: 8192 (order: 3, 32768 bytes, linear)
Sun May 12 06:14:11 2024 kern.info kernel: [    0.000000] Inode-cache hash table entries: 4096 (order: 2, 16384 bytes, linear)
Sun May 12 06:14:11 2024 kern.info kernel: [    0.000000] Writing ErrCtl register=00000000
Sun May 12 06:14:11 2024 kern.info kernel: [    0.000000] Readback ErrCtl register=00000000
Sun May 12 06:14:11 2024 kern.info kernel: [    0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off
Sun May 12 06:14:11 2024 kern.info kernel: [    0.000000] Memory: 54816K/65536K available (6480K kernel code, 598K rwdata, 1492K rodata, 1212K init, 220K bss, 10720K reserved, 0K cma-reserved)
Sun May 12 06:14:11 2024 kern.info kernel: [    0.000000] SLUB: HWalign=32, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
Sun May 12 06:14:11 2024 kern.info kernel: [    0.000000] NR_IRQS: 51
Sun May 12 06:14:11 2024 kern.info kernel: [    0.000000] CPU clock: 390.000 MHz
Sun May 12 06:14:11 2024 kern.info kernel: [    0.000000] clocksource: MIPS: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 9801335621 ns
Sun May 12 06:14:11 2024 kern.info kernel: [    0.000002] sched_clock: 32 bits at 195MHz, resolution 5ns, wraps every 11012737021ns
Sun May 12 06:14:11 2024 kern.info kernel: [    0.007982] Calibrating delay loop... 259.27 BogoMIPS (lpj=1296384)
Sun May 12 06:14:11 2024 kern.info kernel: [    0.084145] pid_max: default: 32768 minimum: 301
Sun May 12 06:14:11 2024 kern.info kernel: [    0.090418] Mount-cache hash table entries: 1024 (order: 0, 4096 bytes, linear)
Sun May 12 06:14:11 2024 kern.info kernel: [    0.097719] Mountpoint-cache hash table entries: 1024 (order: 0, 4096 bytes, linear)
Sun May 12 06:14:11 2024 kern.info kernel: [    0.110004] cblist_init_generic: Setting adjustable number of callback queues.
Sun May 12 06:14:11 2024 kern.info kernel: [    0.117269] cblist_init_generic: Setting shift to 0 and lim to 1.
Sun May 12 06:14:11 2024 kern.info kernel: [    0.129590] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
Sun May 12 06:14:11 2024 kern.info kernel: [    0.139469] futex hash table entries: 256 (order: -1, 3072 bytes, linear)
Sun May 12 06:14:11 2024 kern.info kernel: [    0.146524] pinctrl core: initialized pinctrl subsystem
Sun May 12 06:14:11 2024 kern.info kernel: [    0.154947] NET: Registered PF_NETLINK/PF_ROUTE protocol family
Sun May 12 06:14:11 2024 kern.info kernel: [    0.161878] thermal_sys: Registered thermal governor 'step_wise'
Sun May 12 06:14:11 2024 kern.info kernel: [    0.182836] clocksource: Switched to clocksource MIPS
Sun May 12 06:14:11 2024 kern.info kernel: [    0.196806] NET: Registered PF_INET protocol family
Sun May 12 06:14:11 2024 kern.info kernel: [    0.202110] IP idents hash table entries: 2048 (order: 2, 16384 bytes, linear)
Sun May 12 06:14:11 2024 kern.info kernel: [    0.211298] tcp_listen_portaddr_hash hash table entries: 1024 (order: 0, 4096 bytes, linear)
Sun May 12 06:14:11 2024 kern.info kernel: [    0.219832] Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear)
Sun May 12 06:14:11 2024 kern.info kernel: [    0.227587] TCP established hash table entries: 1024 (order: 0, 4096 bytes, linear)
Sun May 12 06:14:11 2024 kern.info kernel: [    0.235256] TCP bind hash table entries: 1024 (order: 1, 8192 bytes, linear)
Sun May 12 06:14:11 2024 kern.info kernel: [    0.242326] TCP: Hash tables configured (established 1024 bind 1024)
Sun May 12 06:14:11 2024 kern.info kernel: [    0.248987] UDP hash table entries: 256 (order: 0, 4096 bytes, linear)
Sun May 12 06:14:11 2024 kern.info kernel: [    0.255614] UDP-Lite hash table entries: 256 (order: 0, 4096 bytes, linear)
Sun May 12 06:14:11 2024 kern.info kernel: [    0.263300] NET: Registered PF_UNIX/PF_LOCAL protocol family
Sun May 12 06:14:11 2024 kern.info kernel: [    0.269019] PCI: CLS 0 bytes, default 32
Sun May 12 06:14:11 2024 kern.info kernel: [    0.278651] workingset: timestamp_bits=14 max_order=14 bucket_order=0
Sun May 12 06:14:11 2024 kern.info kernel: [    0.295943] squashfs: version 4.0 (2009/01/31) Phillip Lougher
Sun May 12 06:14:11 2024 kern.info kernel: [    0.301769] jffs2: version 2.2 (NAND) (SUMMARY) (LZMA) (RTIME) (CMODE_PRIORITY) (c) 2001-2006 Red Hat, Inc.
Sun May 12 06:14:11 2024 kern.info kernel: [    0.314183] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 251)
Sun May 12 06:14:11 2024 kern.info kernel: [    0.324726] pinctrl-single 18040028.pinmux: 64 pins, size 8
Sun May 12 06:14:11 2024 kern.info kernel: [    0.332258] Serial: 8250/16550 driver, 16 ports, IRQ sharing enabled
Sun May 12 06:14:11 2024 kern.info kernel: [    0.343076] printk: console [ttyS0] disabled
Sun May 12 06:14:11 2024 kern.info kernel: [    0.347477] 18020000.uart: ttyS0 at MMIO 0x18020000 (irq = 10, base_baud = 12187500) is a 16550A
Sun May 12 06:14:11 2024 kern.info kernel: [    0.356324] printk: console [ttyS0] enabled
Sun May 12 06:14:11 2024 kern.info kernel: [    0.364746] printk: bootconsole [early0] disabled
Sun May 12 06:14:11 2024 kern.info kernel: [    0.403812] gpio_spi@0 enforce active low on chipselect handle
Sun May 12 06:14:11 2024 kern.info kernel: [    0.415673] spi-nor spi0.0: mx25l6405d (8192 Kbytes)
Sun May 12 06:14:11 2024 kern.notice kernel: [    0.420892] 5 fixed-partitions partitions found on MTD device spi0.0
Sun May 12 06:14:11 2024 kern.err kernel: [    0.427405] OF: Bad cell count for /ahb/spi@1f000000/flash@0/partitions
Sun May 12 06:14:11 2024 kern.err kernel: [    0.434122] OF: Bad cell count for /ahb/spi@1f000000/flash@0/partitions
Sun May 12 06:14:11 2024 kern.notice kernel: [    0.441164] Creating 5 MTD partitions on "spi0.0":
Sun May 12 06:14:11 2024 kern.notice kernel: [    0.446048] 0x000000000000-0x000000040000 : "u-boot"
Sun May 12 06:14:11 2024 kern.notice kernel: [    0.463192] 0x000000040000-0x000000050000 : "u-boot-env"
Sun May 12 06:14:11 2024 kern.notice kernel: [    0.470285] 0x000000050000-0x0000007b0000 : "firmware"
Sun May 12 06:14:11 2024 kern.notice kernel: [    0.480208] 2 uimage-fw partitions found on MTD device firmware
Sun May 12 06:14:11 2024 kern.notice kernel: [    0.486269] Creating 2 MTD partitions on "firmware":
Sun May 12 06:14:11 2024 kern.notice kernel: [    0.491264] 0x000000000000-0x000000290000 : "kernel"
Sun May 12 06:14:11 2024 kern.notice kernel: [    0.497899] 0x000000290000-0x000000760000 : "rootfs"
Sun May 12 06:14:11 2024 kern.info kernel: [    0.507253] mtd: setting mtd4 (rootfs) as root device
Sun May 12 06:14:11 2024 kern.notice kernel: [    0.512498] 1 squashfs-split partitions found on MTD device rootfs
Sun May 12 06:14:11 2024 kern.notice kernel: [    0.518791] 0x0000005f0000-0x000000760000 : "rootfs_data"
Sun May 12 06:14:11 2024 kern.notice kernel: [    0.525953] 0x0000007b0000-0x0000007f0000 : "cfg"
Sun May 12 06:14:11 2024 kern.notice kernel: [    0.535006] 0x0000007f0000-0x000000800000 : "art"
Sun May 12 06:14:11 2024 kern.err kernel: [    0.541658] OF: Bad cell count for /ahb/spi@1f000000/flash@0/partitions
Sun May 12 06:14:11 2024 kern.info kernel: [    1.245332] switch0: Atheros AR8327 rev. 4 switch registered on mdio.0
Sun May 12 06:14:11 2024 kern.info kernel: [    1.900215] ag71xx 19000000.eth: connected to PHY at fixed-0:00 [uid=00000000, driver=Generic PHY]
Sun May 12 06:14:11 2024 kern.info kernel: [    1.910424] eth0: Atheros AG71xx at 0xb9000000, irq 4, mode: rgmii
Sun May 12 06:14:11 2024 kern.info kernel: [    2.255483] ag71xx 1a000000.eth: connected to PHY at fixed-0:01 [uid=00000000, driver=Generic PHY]
Sun May 12 06:14:11 2024 kern.info kernel: [    2.265726] eth1: Atheros AG71xx at 0xba000000, irq 5, mode: gmii
Sun May 12 06:14:11 2024 kern.info kernel: [    2.272620] i2c_dev: i2c /dev entries driver
Sun May 12 06:14:11 2024 kern.info kernel: [    2.280822] NET: Registered PF_INET6 protocol family
Sun May 12 06:14:11 2024 kern.info kernel: [    2.301421] Segment Routing with IPv6
Sun May 12 06:14:11 2024 kern.info kernel: [    2.305363] In-situ OAM (IOAM) with IPv6
Sun May 12 06:14:11 2024 kern.info kernel: [    2.309510] NET: Registered PF_PACKET protocol family
Sun May 12 06:14:11 2024 kern.info kernel: [    2.314732] bridge: filtering via arp/ip/ip6tables is no longer available by default. Update your scripts to load br_netfilter if you need this.
Sun May 12 06:14:11 2024 kern.info kernel: [    2.328687] 8021q: 802.1Q VLAN Support v1.8
Sun May 12 06:14:11 2024 kern.warn kernel: [    2.336594] ar724x-pci 180c0000.pcie: PCIe link is down
Sun May 12 06:14:11 2024 kern.info kernel: [    2.342166] PCI host bridge to bus 0000:00
Sun May 12 06:14:11 2024 kern.info kernel: [    2.346373] pci_bus 0000:00: root bus resource [mem 0x10000000-0x13ffffff]
Sun May 12 06:14:11 2024 kern.info kernel: [    2.353309] pci_bus 0000:00: root bus resource [io  0x0000]
Sun May 12 06:14:11 2024 kern.info kernel: [    2.358910] pci_bus 0000:00: No busn resource found for root bus, will use [bus 00-ff]
Sun May 12 06:14:11 2024 kern.info kernel: [    2.368265] pci_bus 0000:00: busn_res: [bus 00-ff] end is updated to 00
Sun May 12 06:14:11 2024 kern.info kernel: [    2.376986] gpio-export gpio-export: 5 gpio(s) exported
Sun May 12 06:14:11 2024 kern.info kernel: [    2.391142] clk: Disabling unused clocks
Sun May 12 06:14:11 2024 kern.info kernel: [    2.411995] VFS: Mounted root (squashfs filesystem) readonly on device 31:4.
Sun May 12 06:14:11 2024 kern.info kernel: [    2.429124] Freeing unused kernel image (initmem) memory: 1212K
Sun May 12 06:14:11 2024 kern.warn kernel: [    2.435126] This architecture does not have kernel memory protection.
Sun May 12 06:14:11 2024 kern.info kernel: [    2.441602] Run /sbin/init as init process
Sun May 12 06:14:11 2024 kern.debug kernel: [    2.445728]   with arguments:
Sun May 12 06:14:11 2024 kern.debug kernel: [    2.445736]     /sbin/init
Sun May 12 06:14:11 2024 kern.debug kernel: [    2.445746]   with environment:
Sun May 12 06:14:11 2024 kern.debug kernel: [    2.445755]     HOME=/
Sun May 12 06:14:11 2024 kern.debug kernel: [    2.445764]     TERM=linux
Sun May 12 06:14:11 2024 user.info kernel: [    3.749930] init: Console is alive
Sun May 12 06:14:11 2024 user.info kernel: [    3.754227] init: - watchdog -
Sun May 12 06:14:11 2024 user.info kernel: [    3.757823] init: Watchdog has previously reset the system
Sun May 12 06:14:11 2024 user.info kernel: [    6.204982] kmodloader: loading kernel modules from /etc/modules-boot.d/*
Sun May 12 06:14:11 2024 kern.info kernel: [    6.356234] usbcore: registered new interface driver usbfs
Sun May 12 06:14:11 2024 kern.info kernel: [    6.361866] usbcore: registered new interface driver hub
Sun May 12 06:14:11 2024 kern.info kernel: [    6.367418] usbcore: registered new device driver usb
Sun May 12 06:14:11 2024 kern.info kernel: [    6.397079] ehci-platform 1b000000.usb: EHCI Host Controller
Sun May 12 06:14:11 2024 kern.info kernel: [    6.402918] ehci-platform 1b000000.usb: new USB bus registered, assigned bus number 1
Sun May 12 06:14:11 2024 kern.info kernel: [    6.411028] ehci-platform 1b000000.usb: irq 3, io mem 0x1b000000
Sun May 12 06:14:11 2024 kern.info kernel: [    6.442889] ehci-platform 1b000000.usb: USB 2.0 started, EHCI 1.00
Sun May 12 06:14:11 2024 kern.info kernel: [    6.450711] hub 1-0:1.0: USB hub found
Sun May 12 06:14:11 2024 kern.info kernel: [    6.455874] hub 1-0:1.0: 1 port detected
Sun May 12 06:14:11 2024 user.info kernel: [    6.476923] kmodloader: done loading kernel modules from /etc/modules-boot.d/*
Sun May 12 06:14:11 2024 user.info kernel: [    6.495117] init: - preinit -
Sun May 12 06:14:11 2024 kern.notice kernel: [   11.492869] random: crng init done
Sun May 12 06:14:11 2024 kern.info kernel: [   14.263359] eth0: link up (1000Mbps/Full duplex)
Sun May 12 06:14:11 2024 kern.info kernel: [   14.270269] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
Sun May 12 06:14:11 2024 kern.info kernel: [   14.285967] IPv6: ADDRCONF(NETDEV_CHANGE): eth0.1: link becomes ready
Sun May 12 06:14:11 2024 kern.notice kernel: [   16.820680] jffs2: notice: (413) jffs2_build_xattr_subsystem: complete building xattr subsystem, 30 of xdatum (19 unchecked, 8 orphan) and 36 of xref (8 dead, 0 orphan) found.
Sun May 12 06:14:11 2024 user.info kernel: [   16.843238] mount_root: switching to jffs2 overlay
Sun May 12 06:14:11 2024 kern.warn kernel: [   16.852937] overlayfs: upper fs does not support tmpfile.
Sun May 12 06:14:11 2024 user.warn kernel: [   16.877249] urandom-seed: Seeding with /etc/urandom.seed
Sun May 12 06:14:11 2024 kern.info kernel: [   16.999341] eth0: link down
Sun May 12 06:14:11 2024 user.info kernel: [   17.050548] procd: - early -
Sun May 12 06:14:11 2024 user.info kernel: [   17.054161] procd: - watchdog -
Sun May 12 06:14:11 2024 user.info kernel: [   17.057824] procd: Watchdog has previously reset the system
Sun May 12 06:14:11 2024 user.info kernel: [   17.906795] procd: - watchdog -
Sun May 12 06:14:11 2024 user.info kernel: [   17.910168] procd: Watchdog has previously reset the system
Sun May 12 06:14:11 2024 user.info kernel: [   17.925430] procd: - ubus -
Sun May 12 06:14:11 2024 user.info kernel: [   18.316654] procd: - init -
Sun May 12 06:14:11 2024 user.info kernel: [   20.097736] kmodloader: loading kernel modules from /etc/modules.d/*
Sun May 12 06:14:11 2024 user.info kernel: [   20.109960] kmodloader: done loading kernel modules from /etc/modules.d/*
Sun May 12 06:14:12 2024 authpriv.info dropbear[841]: Not backgrounding
Sun May 12 06:14:23 2024 user.notice : Added device handler type: bonding
Sun May 12 06:14:23 2024 user.notice : Added device handler type: 8021ad
Sun May 12 06:14:23 2024 user.notice : Added device handler type: 8021q
Sun May 12 06:14:23 2024 user.notice : Added device handler type: macvlan
Sun May 12 06:14:23 2024 user.notice : Added device handler type: veth
Sun May 12 06:14:23 2024 user.notice : Added device handler type: bridge
Sun May 12 06:14:23 2024 user.notice : Added device handler type: Network device
Sun May 12 06:14:23 2024 user.notice : Added device handler type: tunnel
Sun May 12 06:14:32 2024 daemon.warn netifd: You have delegated IPv6-prefixes but haven't assigned them to any interface. Did you forget to set option ip6assign on your lan-interfaces?
Sun May 12 06:14:32 2024 kern.info kernel: [   46.530343] eth0: link up (1000Mbps/Full duplex)
Sun May 12 06:14:32 2024 kern.info kernel: [   46.543513] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
Sun May 12 06:14:32 2024 kern.info kernel: [   46.573714] br-lan: port 1(eth0.1) entered blocking state
Sun May 12 06:14:32 2024 kern.info kernel: [   46.579186] br-lan: port 1(eth0.1) entered disabled state
Sun May 12 06:14:32 2024 kern.info kernel: [   46.585156] device eth0.1 entered promiscuous mode
Sun May 12 06:14:32 2024 kern.info kernel: [   46.589990] device eth0 entered promiscuous mode
Sun May 12 06:14:32 2024 kern.info kernel: [   46.617562] br-lan: port 1(eth0.1) entered blocking state
Sun May 12 06:14:32 2024 kern.info kernel: [   46.623104] br-lan: port 1(eth0.1) entered forwarding state
Sun May 12 06:14:32 2024 daemon.notice netifd: Interface 'lan' is enabled
Sun May 12 06:14:32 2024 daemon.notice netifd: Interface 'lan' is setting up now
Sun May 12 06:14:32 2024 daemon.notice netifd: Interface 'lan' is now up
Sun May 12 06:14:32 2024 daemon.notice netifd: bridge 'br-lan' link is up
Sun May 12 06:14:32 2024 daemon.notice netifd: Interface 'lan' has link connectivity
Sun May 12 06:14:32 2024 daemon.notice netifd: Interface 'loopback' is enabled
Sun May 12 06:14:32 2024 daemon.notice netifd: Interface 'loopback' is setting up now
Sun May 12 06:14:32 2024 daemon.notice netifd: Interface 'loopback' is now up
Sun May 12 06:14:32 2024 kern.info kernel: [   46.714682] eth1: link up (1000Mbps/Full duplex)
Sun May 12 06:14:32 2024 kern.info kernel: [   46.719860] IPv6: ADDRCONF(NETDEV_CHANGE): eth1: link becomes ready
Sun May 12 06:14:32 2024 daemon.notice netifd: Interface 'wan' is enabled
Sun May 12 06:14:32 2024 daemon.notice netifd: Interface 'wan6' is enabled
Sun May 12 06:14:32 2024 daemon.notice netifd: bridge 'br-lan' link is down
Sun May 12 06:14:32 2024 daemon.notice netifd: Interface 'lan' has link connectivity loss
Sun May 12 06:14:32 2024 daemon.notice netifd: Network device 'eth0' link is up
Sun May 12 06:14:32 2024 daemon.notice netifd: VLAN 'eth0.1' link is up
Sun May 12 06:14:32 2024 daemon.notice netifd: bridge 'br-lan' link is up
Sun May 12 06:14:32 2024 daemon.notice netifd: Interface 'lan' has link connectivity
Sun May 12 06:14:32 2024 daemon.notice netifd: Network device 'lo' link is up
Sun May 12 06:14:32 2024 daemon.notice netifd: Interface 'loopback' has link connectivity
Sun May 12 06:14:32 2024 daemon.notice netifd: Network device 'eth1' link is up
Sun May 12 06:14:32 2024 daemon.notice netifd: Interface 'wan' has link connectivity
Sun May 12 06:14:32 2024 daemon.notice netifd: Interface 'wan' is setting up now
Sun May 12 06:14:32 2024 daemon.notice netifd: Interface 'wan6' has link connectivity
Sun May 12 06:14:33 2024 daemon.notice netifd: Interface 'wan6' is setting up now
Sun May 12 06:14:33 2024 kern.info kernel: [   47.532924] IPv6: ADDRCONF(NETDEV_CHANGE): br-lan: link becomes ready
Sun May 12 06:14:33 2024 daemon.notice netifd: wan (1328): udhcpc: started, v1.36.1
Sun May 12 06:14:34 2024 daemon.err odhcp6c[1335]: Failed to send RS (Address not available)
Sun May 12 06:14:36 2024 daemon.notice netifd: wan (1328): udhcpc: broadcasting discover
Sun May 12 06:14:36 2024 daemon.info procd: - init complete -
Sun May 12 06:14:36 2024 user.notice firewall: Reloading firewall due to ifup of lan (br-lan)
Sun May 12 06:14:39 2024 daemon.notice netifd: wan (1328): udhcpc: broadcasting discover
Sun May 12 06:14:42 2024 daemon.notice netifd: wan (1328): udhcpc: broadcasting discover
Sun May 12 06:15:45 2024 authpriv.info dropbear[1503]: Child connection from 10.98.1.23:40520
Sun May 12 06:15:48 2024 authpriv.notice dropbear[1503]: Password auth succeeded for 'root' from 10.98.1.23:40520

You see the same ~26 seconds for the switch to come up, which is very long.