Configuration loss after reboot

Hi,

We have been building OpenWrt for our custom hardware (based on TP-LINK MR3020) for a few years and I am most of the way through updating our build procedures and custom programs to run with OpenWrt 18. (We have been stuck on OpenWrt 14 until now.)

What I have noticed is this sequence of events:

  1. files in /etc/ are preserved across a firmware upgrade (good)
  2. on the first reboot after the firmware upgrade, the device reboots with "factory default" configuration i.e. the /etc/ directory tree has reverted to the contents of /rom/etc/ (bad!)
  3. I apply the correct configuration (e.g. by issuing appropriate UCI commands including UCI COMMIT)
  4. the next reboot will preserve the correct configuration (good).

Everything in /overlay/upper/etc/ looks OK after the firmware upgrade, but it gets reloaded from /rom/etc/ on the first reboot after the upgrade.

It's only /etc/ which is being reloaded from /rom/etc/. We have another directory tree which is routinely updated, and consequently is listed in /overlay/upper/, and it is not lost on this reboot.

Any suggestions as to where I should start looking?

Thanks!

Might be that you're running out of space so there's no room left for saving changes?

2 Likes

No, there's plenty of space, especially after I trimmed the Bluetooth stuff.
Note - the local configuration files etc. are preserved across the firmware update; it's the next reboot which causes them to be lost.

A bootlog could be helpful.

What does mount show on the "first" reboot? On the second?

Which version of https://openwrt.org/toh/tp-link/tl-mr3020? Namely, how much flash and RAM and which SoC is on your custom board?

Thanks for your comments. Unfortunately this problem is not reproducible at will, but it has been observed on all three devices which have been upgraded. I tried reverting one to old firmware, doing the upgrade to the new firmware, and then doing a manual reboot - and the configuration files etc were preserved. I have now set that unit to reboot every couple of hours in the hope I might capture something useful. (FYI we have hundreds of these out in the field, running older firmware.)

Here's the output of mount for our old (OpenWrt 14) firmware:

root@OpenWrt:~# mount
rootfs on / type rootfs (rw)
/dev/root on /rom type squashfs (ro,relatime)
proc on /proc type proc (rw,noatime)
sysfs on /sys type sysfs (rw,noatime)
tmpfs on /tmp type tmpfs (rw,nosuid,nodev,noatime)
/dev/mtdblock3 on /overlay type jffs2 (rw,noatime)
overlayfs:/overlay on / type overlayfs (rw,noatime,lowerdir=/,upperdir=/overlay)
tmpfs on /dev type tmpfs (rw,relatime,size=512k,mode=755)
devpts on /dev/pts type devpts (rw,relatime,mode=600)
debugfs on /sys/kernel/debug type debugfs (rw,noatime)
root@OpenWrt:~# 

And for the new, OpenWrt18-based firmware:

root@OpenWrt:~# mount
/dev/root on /rom type squashfs (ro,relatime)
proc on /proc type proc (rw,nosuid,nodev,noexec,noatime)
sysfs on /sys type sysfs (rw,nosuid,nodev,noexec,noatime)
tmpfs on /tmp type tmpfs (rw,nosuid,nodev,noatime)
/dev/mtdblock3 on /overlay type jffs2 (rw,noatime)
overlayfs:/overlay on / type overlay (rw,noatime,lowerdir=/,upperdir=/overlay/upper,workdir=/overlay/work)
tmpfs on /dev type tmpfs (rw,nosuid,relatime,size=512k,mode=755)
devpts on /dev/pts type devpts (rw,nosuid,noexec,relatime,mode=600,ptmxmode=000)
debugfs on /sys/kernel/debug type debugfs (rw,noatime)
root@OpenWrt:~# 

Our device is a "modified" MR3020 v1 board: it has the Atheros AR9331 400MHz CPU but our device has 16MB Flash and 64MB RAM. It also has a DS1302 RTC and a custom LCD. I created this definition for it, which is included by target/linux/ar71xx/image/Makefile:

define Device/myWatt-v2
  $(Device/tplink-16mlzma)
  DEVICE_TITLE := Suntrix myWatt v2
  DEVICE_PACKAGES := kmod-usb-core kmod-usb2 kmod-usb-ledtrig-usbport
  BOARDNAME := TL-MR3020
  DEVICE_PROFILE := TLMR3020
  TPLINK_HWID := 0x30200001
  CONSOLE := ttyATH0,115200
endef
TARGET_DEVICES += myWatt-v2

In Menuconfig the device shows up as:
Target System (Atheros AR7xxx/AR9xxx)
Subtarget (Generic)
Target Profile (Suntrix myWatt v2)
Target Images (squashfs)

Thanks.

1 Like

Hi again,

The problem I'm grappling with is not reproducible at will (I haven't found a way to reproduce it), but I have been able to capture some information which may be helpful.

Two days ago I used sysupgrade to load the same new firmware image onto two of our devices. The upgrade appeared to work fine; both devices rebooted with their configurations intact. Our firmware includes a cron job to reboot the devices daily at 2:15 UTC and that's exactly what they did yesterday, roughly 24 hours after the firmware upgrade. One device rebooted correctly; the other rebooted without its correct configuration.

I captured the output of dmesg for both devices from the firmware upgrade and the reboot a day later, and attached them to this discussion (see next posting). The four files are:

Suntrix-dmesg_upgrade.txt - dmesg log from immediately after the firmware upgrade on the 'bad' device
Suntrix-dmesg_reboot.txt - dmesg log from the reboot 24 hours later, this reboot, this caused loss of configuration

Jeremy-dmesg_upgrade.txt - dmesg log from immediate after the firmware upgrade on the 'good' device
Jeremy-dmesg_reboot.xt - dmesg log from reboot 24 hours later, successful reboot with config retained.

Note that I'm calling them 'good' and 'bad' purely for identification. I've seen the same problem occur on both devices at different times, and on other devices too. I don't believe there's a hardware fault.

Examining the two 'upgrade' logs both include this sequence of operations:

[    6.259434] jffs2_scan_eraseblock(): End of filesystem marker found at 0x110000
[    6.265396] jffs2_build_filesystem(): unlocking the mtd device... 
[    6.271393] done.
[    6.273195] jffs2_build_filesystem(): erasing all blocks after the end marker... 
[   31.996454] done.
[   31.996992] jffs2: notice: (386) jffs2_build_xattr_subsystem: complete building xattr subsystem, 0 of xdatum (0 unchecked, 0 orphan) and 0 of xref (0 dead, 0 orphan) found.
[   32.014570] mount_root: overlay filesystem has not been fully initialized yet
[   32.486508] mount_root: switching to jffs2 overlay

but they differ in the "End of filesystem" marker; the 'good' one is at 0x110000, the 'bad' one is at 0x120000. Also the upgrade log for the 'bad' device concludes with the message:

[  156.542134] jffs2: Newly-erased block contained word 0x19852003 at offset 0x00000000

which does not appear in the 'upgrade' log for the 'good' device.

Examining the 'reboot' logs I saw this rather telling message in the log for the 'bad' device:

[    5.820287] mount_root: no usable overlay filesystem found, using tmpfs overlay

but the 'good' device has the expected:

[    5.941434] jffs2: notice: (386) jffs2_build_xattr_subsystem: complete building xattr subsystem, 0 of xdatum (0 unchecked, 0 orphan) and 0 of xref (0 dead, 0 orphan) found.
[    5.957684] mount_root: switching to jffs2 overlay

Suntrix-dmesg_upgrade.txt

[    0.000000] Linux version 4.9.160 (jeremy@devtest) (gcc version 7.3.0 (OpenWrt GCC 7.3.0 r7405-06a20af) ) #0 Sun Mar 3 17:14:45 2019
[    0.000000] MyLoader: sysp=07c3cb73, boardp=69db762d, parts=24de692d
[    0.000000] bootconsole [early0] enabled
[    0.000000] CPU0 revision is: 00019374 (MIPS 24Kc)
[    0.000000] SoC: Atheros AR9330 rev 1
[    0.000000] Determined physical RAM map:
[    0.000000]  memory: 04000000 @ 00000000 (usable)
[    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] On node 0 totalpages: 16384
[    0.000000] free_area_init_node: node 0, pgdat 804373e4, node_mem_map 81000020
[    0.000000]   Normal zone: 128 pages used for memmap
[    0.000000]   Normal zone: 0 pages reserved
[    0.000000]   Normal zone: 16384 pages, LIFO batch:3
[    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: 16256
[    0.000000] Kernel command line:  board=TL-MR3020  console=ttyATH0,115200 rootfstype=squashfs,jffs2 noinitrd
[    0.000000] PID hash table entries: 256 (order: -2, 1024 bytes)
[    0.000000] Dentry cache hash table entries: 8192 (order: 3, 32768 bytes)
[    0.000000] Inode-cache hash table entries: 4096 (order: 2, 16384 bytes)
[    0.000000] Writing ErrCtl register=00000000
[    0.000000] Readback ErrCtl register=00000000
[    0.000000] Memory: 60100K/65536K available (2991K kernel code, 165K rwdata, 780K rodata, 280K init, 203K bss, 5436K 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] Clocks: CPU:400.000MHz, DDR:400.000MHz, AHB:200.000MHz, Ref:25.000MHz
[    0.000000] clocksource: MIPS: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 9556302233 ns
[    0.000013] sched_clock: 32 bits at 200MHz, resolution 5ns, wraps every 10737418237ns
[    0.007566] Calibrating delay loop... 265.42 BogoMIPS (lpj=1327104)
[    0.088749] pid_max: default: 32768 minimum: 301
[    0.093331] Mount-cache hash table entries: 1024 (order: 0, 4096 bytes)
[    0.099504] Mountpoint-cache hash table entries: 1024 (order: 0, 4096 bytes)
[    0.110140] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[    0.118178] futex hash table entries: 256 (order: -1, 3072 bytes)
[    0.124884] NET: Registered protocol family 16
[    0.130246] MIPS: machine is TP-LINK TL-MR3020
[    0.425536] clocksource: Switched to clocksource MIPS
[    0.430465] NET: Registered protocol family 2
[    0.434403] TCP established hash table entries: 1024 (order: 0, 4096 bytes)
[    0.440018] TCP bind hash table entries: 1024 (order: 0, 4096 bytes)
[    0.446020] TCP: Hash tables configured (established 1024 bind 1024)
[    0.452207] UDP hash table entries: 256 (order: 0, 4096 bytes)
[    0.457698] UDP-Lite hash table entries: 256 (order: 0, 4096 bytes)
[    0.463943] NET: Registered protocol family 1
[    0.467857] PCI: CLS 0 bytes, default 32
[    0.474221] Crashlog allocated RAM at address 0x3f00000
[    0.479476] workingset: timestamp_bits=30 max_order=14 bucket_order=0
[    0.494112] squashfs: version 4.0 (2009/01/31) Phillip Lougher
[    0.498356] jffs2: version 2.2 (NAND) (SUMMARY) (LZMA) (RTIME) (CMODE_PRIORITY) (c) 2001-2006 Red Hat, Inc.
[    0.519978] io scheduler noop registered
[    0.522346] io scheduler deadline registered (default)
[    0.527852] Serial: 8250/16550 driver, 1 ports, IRQ sharing disabled
[    0.533905] ar933x-uart: ttyATH0 at MMIO 0x18020000 (irq = 11, base_baud = 1562500) is a AR933X UART
[    0.542550] console [ttyATH0] enabled
[    0.549354] bootconsole [early0] disabled
[    0.561905] m25p80 spi0.0: found w25q128, expected m25p80
[    0.577318] m25p80 spi0.0: w25q128 (16384 Kbytes)
[    0.580923] 5 tp-link partitions found on MTD device spi0.0
[    0.586160] Creating 5 MTD partitions on "spi0.0":
[    0.590913] 0x000000000000-0x000000020000 : "u-boot"
[    0.598575] 0x000000020000-0x0000001654bc : "kernel"
[    0.604938] 0x0000001654bc-0x000000ff0000 : "rootfs"
[    0.610711] mtd: device 2 (rootfs) set to be root filesystem
[    0.614963] 1 squashfs-split partitions found on MTD device rootfs
[    0.621179] 0x000000700000-0x000000ff0000 : "rootfs_data"
[    0.629457] 0x000000ff0000-0x000001000000 : "art"
[    0.635522] 0x000000020000-0x000000ff0000 : "firmware"
[    0.643531] libphy: Fixed MDIO Bus: probed
[    0.665607] libphy: ag71xx_mdio: probed
[    1.297249] ag71xx ag71xx.0: connected to PHY at ag71xx-mdio.1:04 [uid=004dd041, driver=Generic PHY]
[    1.306029] eth0: Atheros AG71xx at 0xb9000000, irq 4, mode:MII
[    1.311874] NET: Registered protocol family 17
[    1.315465] 8021q: 802.1Q VLAN Support v1.8
[    1.322864] hctosys: unable to open rtc device (rtc0)
[    1.331237] VFS: Mounted root (squashfs filesystem) readonly on device 31:2.
[    1.339065] Freeing unused kernel memory: 280K
[    1.342048] This architecture does not have kernel memory protection.
[    2.210332] init: Console is alive
[    2.212578] init: - watchdog -
[    2.515552] random: fast init done
[    4.275308] kmodloader: loading kernel modules from /etc/modules-boot.d/*
[    4.417816] usbcore: registered new interface driver usbfs
[    4.421961] usbcore: registered new interface driver hub
[    4.427347] usbcore: registered new device driver usb
[    4.438003] ds1302: RTC found.
[    4.439994] rtc_time	: 02:49:52
[    4.439994] rtc_date	: 2019-03-05
[    4.451120] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[    4.474595] ar933x_lcd initialized
[    4.476565] ar933x_lcd: ar933x_lcd device registered with major 251
[    4.496577] SCSI subsystem initialized
[    4.505805] ehci-platform: EHCI generic platform driver
[    4.509713] ehci-platform ehci-platform: EHCI Host Controller
[    4.515358] ehci-platform ehci-platform: new USB bus registered, assigned bus number 1
[    4.525383] ehci-platform ehci-platform: irq 3, io mem 0x1b000000
[    4.555596] ehci-platform ehci-platform: USB 2.0 started, EHCI 1.00
[    4.561690] hub 1-0:1.0: USB hub found
[    4.564587] hub 1-0:1.0: 1 port detected
[    4.575665] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
[    4.582420] ohci-platform: OHCI generic platform driver
[    4.595490] usbcore: registered new interface driver usb-storage
[    4.600946] kmodloader: done loading kernel modules from /etc/modules-boot.d/*
[    4.617910] init: - preinit -
[    5.244224] usb 1-1: new high-speed USB device number 2 using ehci-platform
[    5.460608] hub 1-1:1.0: USB hub found
[    5.464488] hub 1-1:1.0: 4 ports detected
[    5.535970] random: procd: uninitialized urandom read (4 bytes read)
[    5.835662] usb 1-1.1: new full-speed USB device number 3 using ehci-platform
[    6.146763] usb 1-1.3: new full-speed USB device number 4 using ehci-platform
[    6.283776] jffs2_scan_eraseblock(): End of filesystem marker found at 0x120000
[    6.289756] jffs2_build_filesystem(): unlocking the mtd device... 
[    6.295771] done.
[    6.297529] jffs2_build_filesystem(): erasing all blocks after the end marker... 
[   34.325628] done.
[   34.326158] jffs2: notice: (386) jffs2_build_xattr_subsystem: complete building xattr subsystem, 0 of xdatum (0 unchecked, 0 orphan) and 0 of xref (0 dead, 0 orphan) found.
[   34.343778] mount_root: overlay filesystem has not been fully initialized yet
[   34.864595] mount_root: switching to jffs2 overlay
[  120.915632] random: crng init done
[  121.423299] urandom-seed: Seed file not found (/etc/urandom.seed)
[  121.690781] procd: - early -
[  121.692332] procd: - watchdog -
[  122.462187] procd: - watchdog -
[  122.464276] procd: - ubus -
[  123.036158] procd: - init -
[  123.834303] kmodloader: loading kernel modules from /etc/modules.d/*
[  124.133773] tun: Universal TUN/TAP device driver, 1.6
[  124.137456] tun: (C) 1999-2004 Max Krasnyansky <maxk@qualcomm.com>
[  124.201117] i2c /dev entries driver
[  124.243581] hidraw: raw HID events driver (C) Jiri Kosina
[  124.337949] Bluetooth: Core ver 2.22
[  124.340192] NET: Registered protocol family 31
[  124.344503] Bluetooth: HCI device and connection manager initialized
[  124.350926] Bluetooth: HCI socket layer initialized
[  124.355725] Bluetooth: L2CAP socket layer initialized
[  124.360775] Bluetooth: SCO socket layer initialized
[  124.467931] Bluetooth: BNEP (Ethernet Emulation) ver 1.3
[  124.471797] Bluetooth: BNEP filters: protocol multicast
[  124.477103] Bluetooth: BNEP socket layer initialized
[  124.556533] usbcore: registered new interface driver btusb
[  124.578717] usbcore: registered new interface driver cdc_acm
[  124.582927] cdc_acm: USB Abstract Control Model driver for USB modems and ISDN adapters
[  124.634742] Loading modules backported from Linux version wt-2017-11-01-0-gfe248fc2c180
[  124.641392] Backport generated by backports.git v4.14-rc2-1-31-g86cf0e5d
[  124.691440] Bluetooth: HCI UART driver ver 2.3
[  124.694492] Bluetooth: HCI UART protocol H4 registered
[  124.699610] Bluetooth: HCI UART protocol BCSP registered
[  124.827343] Bluetooth: HIDP (Human Interface Emulation) ver 1.2
[  124.831871] Bluetooth: HIDP socket layer initialized
[  124.874127] nf_conntrack version 0.5.0 (1024 buckets, 4096 max)
[  125.005849] Bluetooth: RFCOMM TTY layer initialized
[  125.009314] Bluetooth: RFCOMM socket layer initialized
[  125.014438] Bluetooth: RFCOMM ver 1.11
[  125.040714] usbcore: registered new interface driver usbhid
[  125.044837] usbhid: USB HID core driver
[  125.081994] usbcore: registered new interface driver usbserial
[  125.086627] usbcore: registered new interface driver usbserial_generic
[  125.093018] usbserial: USB Serial support registered for generic
[  125.170869] xt_time: kernel timezone is -0000
[  125.184727] usbcore: registered new interface driver cdc_ether
[  125.269253] usbcore: registered new interface driver ftdi_sio
[  125.273692] usbserial: USB Serial support registered for FTDI USB Serial Device
[  125.298536] ip_tables: (C) 2000-2006 Netfilter Core Team
[  125.328913] usbcore: registered new interface driver keyspan
[  125.333245] usbserial: USB Serial support registered for Keyspan - (without firmware)
[  125.341155] usbserial: USB Serial support registered for Keyspan 1 port adapter
[  125.348409] usbserial: USB Serial support registered for Keyspan 2 port adapter
[  125.355724] usbserial: USB Serial support registered for Keyspan 4 port adapter
[  125.509226] usbcore: registered new interface driver pl2303
[  125.513535] usbserial: USB Serial support registered for pl2303
[  125.519406] pl2303 1-1.1:1.0: pl2303 converter detected
[  125.539507] usb 1-1.1: pl2303 converter now attached to ttyUSB0
[  125.560623] PPP generic driver version 2.4.2
[  125.577902] NET: Registered protocol family 24
[  125.585132] usbcore: registered new interface driver rndis_host
[  125.714490] ath: EEPROM regdomain: 0x0
[  125.714505] ath: EEPROM indicates default country code should be used
[  125.714510] ath: doing EEPROM country->regdmn map search
[  125.714531] ath: country maps to regdmn code: 0x3a
[  125.714539] ath: Country alpha2 being used: US
[  125.714544] ath: Regpair used: 0x3a
[  125.726569] ieee80211 phy0: Selected rate control algorithm 'minstrel_ht'
[  125.732489] ieee80211 phy0: Atheros AR9330 Rev:1 mem=0xb8100000, irq=2
[  125.786212] kmodloader: done loading kernel modules from /etc/modules.d/*
[  145.749763] br-lan: port 1(eth0) entered blocking state
[  145.753551] br-lan: port 1(eth0) entered disabled state
[  145.759348] device eth0 entered promiscuous mode
[  147.398980] ath: EEPROM regdomain: 0x8024
[  147.398994] ath: EEPROM indicates we should expect a country code
[  147.399001] ath: doing EEPROM country->regdmn map search
[  147.399007] ath: country maps to regdmn code: 0x21
[  147.399015] ath: Country alpha2 being used: AU
[  147.399021] ath: Regpair used: 0x21
[  147.399030] ath: regdomain 0x8024 dynamically updated by user
[  152.175157] wlan0: authenticate with f0:9f:c2:7d:6d:76
[  152.190658] wlan0: send auth to f0:9f:c2:7d:6d:76 (try 1/3)
[  152.203830] wlan0: authenticated
[  152.246002] wlan0: associate with f0:9f:c2:7d:6d:76 (try 1/3)
[  152.259673] wlan0: RX AssocResp from f0:9f:c2:7d:6d:76 (capab=0x431 status=0 aid=1)
[  152.266431] wlan0: associated
[  156.542134] jffs2: Newly-erased block contained word 0x19852003 at offset 0x00000000

Suntrix-dmesg_reboot.txt

[    0.000000] Linux version 4.9.160 (jeremy@devtest) (gcc version 7.3.0 (OpenWrt GCC 7.3.0 r7405-06a20af) ) #0 Sun Mar 3 17:14:45 2019
[    0.000000] MyLoader: sysp=07c3cb73, boardp=69db762d, parts=24de692d
[    0.000000] bootconsole [early0] enabled
[    0.000000] CPU0 revision is: 00019374 (MIPS 24Kc)
[    0.000000] SoC: Atheros AR9330 rev 1
[    0.000000] Determined physical RAM map:
[    0.000000]  memory: 04000000 @ 00000000 (usable)
[    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] On node 0 totalpages: 16384
[    0.000000] free_area_init_node: node 0, pgdat 804373e4, node_mem_map 81000020
[    0.000000]   Normal zone: 128 pages used for memmap
[    0.000000]   Normal zone: 0 pages reserved
[    0.000000]   Normal zone: 16384 pages, LIFO batch:3
[    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: 16256
[    0.000000] Kernel command line:  board=TL-MR3020  console=ttyATH0,115200 rootfstype=squashfs,jffs2 noinitrd
[    0.000000] PID hash table entries: 256 (order: -2, 1024 bytes)
[    0.000000] Dentry cache hash table entries: 8192 (order: 3, 32768 bytes)
[    0.000000] Inode-cache hash table entries: 4096 (order: 2, 16384 bytes)
[    0.000000] Writing ErrCtl register=00000000
[    0.000000] Readback ErrCtl register=00000000
[    0.000000] Memory: 60100K/65536K available (2991K kernel code, 165K rwdata, 780K rodata, 280K init, 203K bss, 5436K 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] Clocks: CPU:400.000MHz, DDR:400.000MHz, AHB:200.000MHz, Ref:25.000MHz
[    0.000000] clocksource: MIPS: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 9556302233 ns
[    0.000014] sched_clock: 32 bits at 200MHz, resolution 5ns, wraps every 10737418237ns
[    0.007566] Calibrating delay loop... 265.42 BogoMIPS (lpj=1327104)
[    0.088749] pid_max: default: 32768 minimum: 301
[    0.093331] Mount-cache hash table entries: 1024 (order: 0, 4096 bytes)
[    0.099504] Mountpoint-cache hash table entries: 1024 (order: 0, 4096 bytes)
[    0.110138] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[    0.118177] futex hash table entries: 256 (order: -1, 3072 bytes)
[    0.124885] NET: Registered protocol family 16
[    0.130247] MIPS: machine is TP-LINK TL-MR3020
[    0.425531] clocksource: Switched to clocksource MIPS
[    0.430457] NET: Registered protocol family 2
[    0.434396] TCP established hash table entries: 1024 (order: 0, 4096 bytes)
[    0.440010] TCP bind hash table entries: 1024 (order: 0, 4096 bytes)
[    0.446012] TCP: Hash tables configured (established 1024 bind 1024)
[    0.452199] UDP hash table entries: 256 (order: 0, 4096 bytes)
[    0.457690] UDP-Lite hash table entries: 256 (order: 0, 4096 bytes)
[    0.463935] NET: Registered protocol family 1
[    0.467848] PCI: CLS 0 bytes, default 32
[    0.474211] Crashlog allocated RAM at address 0x3f00000
[    0.479470] workingset: timestamp_bits=30 max_order=14 bucket_order=0
[    0.494105] squashfs: version 4.0 (2009/01/31) Phillip Lougher
[    0.498348] jffs2: version 2.2 (NAND) (SUMMARY) (LZMA) (RTIME) (CMODE_PRIORITY) (c) 2001-2006 Red Hat, Inc.
[    0.519969] io scheduler noop registered
[    0.522338] io scheduler deadline registered (default)
[    0.527843] Serial: 8250/16550 driver, 1 ports, IRQ sharing disabled
[    0.533896] ar933x-uart: ttyATH0 at MMIO 0x18020000 (irq = 11, base_baud = 1562500) is a AR933X UART
[    0.542542] console [ttyATH0] enabled
[    0.549345] bootconsole [early0] disabled
[    0.561898] m25p80 spi0.0: found w25q128, expected m25p80
[    0.577271] m25p80 spi0.0: w25q128 (16384 Kbytes)
[    0.580880] 5 tp-link partitions found on MTD device spi0.0
[    0.586118] Creating 5 MTD partitions on "spi0.0":
[    0.590870] 0x000000000000-0x000000020000 : "u-boot"
[    0.598537] 0x000000020000-0x0000001654bc : "kernel"
[    0.604894] 0x0000001654bc-0x000000ff0000 : "rootfs"
[    0.610668] mtd: device 2 (rootfs) set to be root filesystem
[    0.614922] 1 squashfs-split partitions found on MTD device rootfs
[    0.621137] 0x000000700000-0x000000ff0000 : "rootfs_data"
[    0.629413] 0x000000ff0000-0x000001000000 : "art"
[    0.635483] 0x000000020000-0x000000ff0000 : "firmware"
[    0.643491] libphy: Fixed MDIO Bus: probed
[    0.665489] libphy: ag71xx_mdio: probed
[    1.297244] ag71xx ag71xx.0: connected to PHY at ag71xx-mdio.1:04 [uid=004dd041, driver=Generic PHY]
[    1.306021] eth0: Atheros AG71xx at 0xb9000000, irq 4, mode:MII
[    1.311866] NET: Registered protocol family 17
[    1.315458] 8021q: 802.1Q VLAN Support v1.8
[    1.322857] hctosys: unable to open rtc device (rtc0)
[    1.331227] VFS: Mounted root (squashfs filesystem) readonly on device 31:2.
[    1.339056] Freeing unused kernel memory: 280K
[    1.342040] This architecture does not have kernel memory protection.
[    2.209756] init: Console is alive
[    2.212005] init: - watchdog -
[    2.525545] random: fast init done
[    4.270292] kmodloader: loading kernel modules from /etc/modules-boot.d/*
[    4.411986] usbcore: registered new interface driver usbfs
[    4.416228] usbcore: registered new interface driver hub
[    4.421438] usbcore: registered new device driver usb
[    4.432093] ds1302: RTC found.
[    4.434082] rtc_time	: 02:15:17
[    4.434082] rtc_date	: 2019-03-06
[    4.445258] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[    4.468755] ar933x_lcd initialized
[    4.470702] ar933x_lcd: ar933x_lcd device registered with major 251
[    4.490126] SCSI subsystem initialized
[    4.499347] ehci-platform: EHCI generic platform driver
[    4.503268] ehci-platform ehci-platform: EHCI Host Controller
[    4.508978] ehci-platform ehci-platform: new USB bus registered, assigned bus number 1
[    4.518906] ehci-platform ehci-platform: irq 3, io mem 0x1b000000
[    4.545586] ehci-platform ehci-platform: USB 2.0 started, EHCI 1.00
[    4.551618] hub 1-0:1.0: USB hub found
[    4.554683] hub 1-0:1.0: 1 port detected
[    4.565407] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
[    4.572149] ohci-platform: OHCI generic platform driver
[    4.585155] usbcore: registered new interface driver usb-storage
[    4.590729] kmodloader: done loading kernel modules from /etc/modules-boot.d/*
[    4.601181] init: - preinit -
[    5.225162] usb 1-1: new high-speed USB device number 2 using ehci-platform
[    5.464293] hub 1-1:1.0: USB hub found
[    5.469393] hub 1-1:1.0: 4 ports detected
[    5.535995] random: procd: uninitialized urandom read (4 bytes read)
[    5.820287] mount_root: no usable overlay filesystem found, using tmpfs overlay
[    5.879654] urandom-seed: Seed file not found (/etc/urandom.seed)
[    5.885124] usb 1-1.1: new full-speed USB device number 3 using ehci-platform
[    6.290508] procd: - early -
[    6.292116] procd: - watchdog -
[    6.343971] usb 1-1.3: new full-speed USB device number 4 using ehci-platform
[    6.936893] random: jshn: uninitialized urandom read (4 bytes read)
[    7.109762] procd: - watchdog -
[    7.111829] procd: - ubus -
[    7.558921] random: jshn: uninitialized urandom read (4 bytes read)
[    7.577845] random: ubusd: uninitialized urandom read (4 bytes read)
[    7.630471] procd: - init -
[    8.433686] kmodloader: loading kernel modules from /etc/modules.d/*
[    8.548755] tun: Universal TUN/TAP device driver, 1.6
[    8.552359] tun: (C) 1999-2004 Max Krasnyansky <maxk@qualcomm.com>
[    8.699879] i2c /dev entries driver
[    8.726719] hidraw: raw HID events driver (C) Jiri Kosina
[    8.804436] Bluetooth: Core ver 2.22
[    8.806779] NET: Registered protocol family 31
[    8.810986] Bluetooth: HCI device and connection manager initialized
[    8.817377] Bluetooth: HCI socket layer initialized
[    8.822191] Bluetooth: L2CAP socket layer initialized
[    8.827276] Bluetooth: SCO socket layer initialized
[    8.987956] Bluetooth: BNEP (Ethernet Emulation) ver 1.3
[    8.991815] Bluetooth: BNEP filters: protocol multicast
[    8.997119] Bluetooth: BNEP socket layer initialized
[    9.033476] usbcore: registered new interface driver btusb
[    9.049555] usbcore: registered new interface driver cdc_acm
[    9.053803] cdc_acm: USB Abstract Control Model driver for USB modems and ISDN adapters
[    9.077513] Loading modules backported from Linux version wt-2017-11-01-0-gfe248fc2c180
[    9.084121] Backport generated by backports.git v4.14-rc2-1-31-g86cf0e5d
[    9.138112] Bluetooth: HCI UART driver ver 2.3
[    9.141105] Bluetooth: HCI UART protocol H4 registered
[    9.146308] Bluetooth: HCI UART protocol BCSP registered
[    9.185746] Bluetooth: HIDP (Human Interface Emulation) ver 1.2
[    9.190273] Bluetooth: HIDP socket layer initialized
[    9.226378] nf_conntrack version 0.5.0 (1024 buckets, 4096 max)
[    9.479636] Bluetooth: RFCOMM TTY layer initialized
[    9.483097] Bluetooth: RFCOMM socket layer initialized
[    9.488309] Bluetooth: RFCOMM ver 1.11
[    9.499476] usbcore: registered new interface driver usbhid
[    9.503593] usbhid: USB HID core driver
[    9.521817] usbcore: registered new interface driver usbserial
[    9.526442] usbcore: registered new interface driver usbserial_generic
[    9.532855] usbserial: USB Serial support registered for generic
[    9.572066] xt_time: kernel timezone is -0000
[    9.588733] usbcore: registered new interface driver cdc_ether
[    9.729282] usbcore: registered new interface driver ftdi_sio
[    9.733703] usbserial: USB Serial support registered for FTDI USB Serial Device
[    9.754285] ip_tables: (C) 2000-2006 Netfilter Core Team
[    9.783096] usbcore: registered new interface driver keyspan
[    9.787553] usbserial: USB Serial support registered for Keyspan - (without firmware)
[    9.795216] usbserial: USB Serial support registered for Keyspan 1 port adapter
[    9.802640] usbserial: USB Serial support registered for Keyspan 2 port adapter
[    9.809914] usbserial: USB Serial support registered for Keyspan 4 port adapter
[    9.959265] usbcore: registered new interface driver pl2303
[    9.963512] usbserial: USB Serial support registered for pl2303
[    9.969472] pl2303 1-1.1:1.0: pl2303 converter detected
[    9.997533] usb 1-1.1: pl2303 converter now attached to ttyUSB0
[   10.010670] PPP generic driver version 2.4.2
[   10.027904] NET: Registered protocol family 24
[   10.039437] usbcore: registered new interface driver rndis_host
[   10.164158] ath: EEPROM regdomain: 0x0
[   10.164174] ath: EEPROM indicates default country code should be used
[   10.164179] ath: doing EEPROM country->regdmn map search
[   10.164199] ath: country maps to regdmn code: 0x3a
[   10.164206] ath: Country alpha2 being used: US
[   10.164212] ath: Regpair used: 0x3a
[   10.176234] ieee80211 phy0: Selected rate control algorithm 'minstrel_ht'
[   10.182113] ieee80211 phy0: Atheros AR9330 Rev:1 mem=0xb8100000, irq=2
[   10.246259] kmodloader: done loading kernel modules from /etc/modules.d/*
[   30.020058] br-lan: port 1(eth0) entered blocking state
[   30.023844] br-lan: port 1(eth0) entered disabled state
[   30.029609] device eth0 entered promiscuous mode
[   62.015603] jffs2: notice: (1630) jffs2_build_xattr_subsystem: complete building xattr subsystem, 0 of xdatum (0 unchecked, 0 orphan) and 0 of xref (0 dead, 0 orphan) found.
[   68.123687] device eth0 left promiscuous mode
[   68.123789] br-lan: port 1(eth0) entered disabled state
[   68.160623] br-lan: port 1(eth0) entered blocking state
[   68.160644] br-lan: port 1(eth0) entered disabled state
[   68.161126] device eth0 entered promiscuous mode
[   70.257479] device eth0 left promiscuous mode
[   70.257577] br-lan: port 1(eth0) entered disabled state
[   70.960450] ath: EEPROM regdomain: 0x8024
[   70.960465] ath: EEPROM indicates we should expect a country code
[   70.960471] ath: doing EEPROM country->regdmn map search
[   70.960478] ath: country maps to regdmn code: 0x21
[   70.960486] ath: Country alpha2 being used: AU
[   70.960491] ath: Regpair used: 0x21
[   70.960500] ath: regdomain 0x8024 dynamically updated by user
[   77.310060] br-lan: port 1(eth0) entered blocking state
[   77.310081] br-lan: port 1(eth0) entered disabled state
[   77.310578] device eth0 entered promiscuous mode
[   78.012069] device eth0 left promiscuous mode
[   78.012170] br-lan: port 1(eth0) entered disabled state
[   85.450089] br-lan: port 1(eth0) entered blocking state
[   85.450110] br-lan: port 1(eth0) entered disabled state
[   85.450628] device eth0 entered promiscuous mode
[  101.355616] random: crng init done
[  101.355639] random: 6 urandom warning(s) missed due to rate limiting

Jeremy-dmesg_upgrade.txt

[    0.000000] Linux version 4.9.160 (jeremy@devtest) (gcc version 7.3.0 (OpenWrt GCC 7.3.0 r7405-06a20af) ) #0 Sun Mar 3 17:14:45 2019
[    0.000000] MyLoader: sysp=07c3cb73, boardp=69db762d, parts=24de692d
[    0.000000] bootconsole [early0] enabled
[    0.000000] CPU0 revision is: 00019374 (MIPS 24Kc)
[    0.000000] SoC: Atheros AR9330 rev 1
[    0.000000] Determined physical RAM map:
[    0.000000]  memory: 04000000 @ 00000000 (usable)
[    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] On node 0 totalpages: 16384
[    0.000000] free_area_init_node: node 0, pgdat 804373e4, node_mem_map 81000020
[    0.000000]   Normal zone: 128 pages used for memmap
[    0.000000]   Normal zone: 0 pages reserved
[    0.000000]   Normal zone: 16384 pages, LIFO batch:3
[    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: 16256
[    0.000000] Kernel command line:  board=TL-MR3020  console=ttyATH0,115200 rootfstype=squashfs,jffs2 noinitrd
[    0.000000] PID hash table entries: 256 (order: -2, 1024 bytes)
[    0.000000] Dentry cache hash table entries: 8192 (order: 3, 32768 bytes)
[    0.000000] Inode-cache hash table entries: 4096 (order: 2, 16384 bytes)
[    0.000000] Writing ErrCtl register=00000000
[    0.000000] Readback ErrCtl register=00000000
[    0.000000] Memory: 60100K/65536K available (2991K kernel code, 165K rwdata, 780K rodata, 280K init, 203K bss, 5436K 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] Clocks: CPU:400.000MHz, DDR:400.000MHz, AHB:200.000MHz, Ref:25.000MHz
[    0.000000] clocksource: MIPS: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 9556302233 ns
[    0.000013] sched_clock: 32 bits at 200MHz, resolution 5ns, wraps every 10737418237ns
[    0.007566] Calibrating delay loop... 265.42 BogoMIPS (lpj=1327104)
[    0.088749] pid_max: default: 32768 minimum: 301
[    0.093332] Mount-cache hash table entries: 1024 (order: 0, 4096 bytes)
[    0.099504] Mountpoint-cache hash table entries: 1024 (order: 0, 4096 bytes)
[    0.110139] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[    0.118177] futex hash table entries: 256 (order: -1, 3072 bytes)
[    0.124884] NET: Registered protocol family 16
[    0.130246] MIPS: machine is TP-LINK TL-MR3020
[    0.425532] clocksource: Switched to clocksource MIPS
[    0.430458] NET: Registered protocol family 2
[    0.434396] TCP established hash table entries: 1024 (order: 0, 4096 bytes)
[    0.440010] TCP bind hash table entries: 1024 (order: 0, 4096 bytes)
[    0.446011] TCP: Hash tables configured (established 1024 bind 1024)
[    0.452198] UDP hash table entries: 256 (order: 0, 4096 bytes)
[    0.457690] UDP-Lite hash table entries: 256 (order: 0, 4096 bytes)
[    0.463935] NET: Registered protocol family 1
[    0.467849] PCI: CLS 0 bytes, default 32
[    0.474212] Crashlog allocated RAM at address 0x3f00000
[    0.479470] workingset: timestamp_bits=30 max_order=14 bucket_order=0
[    0.494106] squashfs: version 4.0 (2009/01/31) Phillip Lougher
[    0.498348] jffs2: version 2.2 (NAND) (SUMMARY) (LZMA) (RTIME) (CMODE_PRIORITY) (c) 2001-2006 Red Hat, Inc.
[    0.519970] io scheduler noop registered
[    0.522338] io scheduler deadline registered (default)
[    0.527843] Serial: 8250/16550 driver, 1 ports, IRQ sharing disabled
[    0.533896] ar933x-uart: ttyATH0 at MMIO 0x18020000 (irq = 11, base_baud = 1562500) is a AR933X UART
[    0.542542] console [ttyATH0] enabled
[    0.549346] bootconsole [early0] disabled
[    0.561900] m25p80 spi0.0: found w25q128, expected m25p80
[    0.577432] m25p80 spi0.0: w25q128 (16384 Kbytes)
[    0.581037] 5 tp-link partitions found on MTD device spi0.0
[    0.586272] Creating 5 MTD partitions on "spi0.0":
[    0.591027] 0x000000000000-0x000000020000 : "u-boot"
[    0.598690] 0x000000020000-0x0000001654bc : "kernel"
[    0.605052] 0x0000001654bc-0x000000ff0000 : "rootfs"
[    0.610825] mtd: device 2 (rootfs) set to be root filesystem
[    0.615086] 1 squashfs-split partitions found on MTD device rootfs
[    0.621302] 0x000000700000-0x000000ff0000 : "rootfs_data"
[    0.629579] 0x000000ff0000-0x000001000000 : "art"
[    0.635726] 0x000000020000-0x000000ff0000 : "firmware"
[    0.643655] libphy: Fixed MDIO Bus: probed
[    0.665732] libphy: ag71xx_mdio: probed
[    1.297245] ag71xx ag71xx.0: connected to PHY at ag71xx-mdio.1:04 [uid=004dd041, driver=Generic PHY]
[    1.306021] eth0: Atheros AG71xx at 0xb9000000, irq 4, mode:MII
[    1.311866] NET: Registered protocol family 17
[    1.315458] 8021q: 802.1Q VLAN Support v1.8
[    1.322857] hctosys: unable to open rtc device (rtc0)
[    1.331235] VFS: Mounted root (squashfs filesystem) readonly on device 31:2.
[    1.339066] Freeing unused kernel memory: 280K
[    1.342048] This architecture does not have kernel memory protection.
[    2.210256] init: Console is alive
[    2.212494] init: - watchdog -
[    2.515549] random: fast init done
[    4.271636] kmodloader: loading kernel modules from /etc/modules-boot.d/*
[    4.414366] usbcore: registered new interface driver usbfs
[    4.418604] usbcore: registered new interface driver hub
[    4.423818] usbcore: registered new device driver usb
[    4.434374] ds1302: RTC found.
[    4.436449] rtc_time	: 03:00:54
[    4.436449] rtc_date	: 2019-03-05
[    4.447565] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[    4.470980] ar933x_lcd initialized
[    4.472933] ar933x_lcd: ar933x_lcd device registered with major 251
[    4.492819] SCSI subsystem initialized
[    4.502025] ehci-platform: EHCI generic platform driver
[    4.506004] ehci-platform ehci-platform: EHCI Host Controller
[    4.511574] ehci-platform ehci-platform: new USB bus registered, assigned bus number 1
[    4.521593] ehci-platform ehci-platform: irq 3, io mem 0x1b000000
[    4.555588] ehci-platform ehci-platform: USB 2.0 started, EHCI 1.00
[    4.561669] hub 1-0:1.0: USB hub found
[    4.564578] hub 1-0:1.0: 1 port detected
[    4.575506] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
[    4.582239] ohci-platform: OHCI generic platform driver
[    4.595246] usbcore: registered new interface driver usb-storage
[    4.600705] kmodloader: done loading kernel modules from /etc/modules-boot.d/*
[    4.617659] init: - preinit -
[    5.242296] usb 1-1: new high-speed USB device number 2 using ehci-platform
[    5.483599] hub 1-1:1.0: USB hub found
[    5.486455] hub 1-1:1.0: 4 ports detected
[    5.513881] random: procd: uninitialized urandom read (4 bytes read)
[    5.896305] usb 1-1.1: new full-speed USB device number 3 using ehci-platform
[    6.185685] usb 1-1.4: new full-speed USB device number 4 using ehci-platform
[    6.259434] jffs2_scan_eraseblock(): End of filesystem marker found at 0x110000
[    6.265396] jffs2_build_filesystem(): unlocking the mtd device... 
[    6.271393] done.
[    6.273195] jffs2_build_filesystem(): erasing all blocks after the end marker... 
[   31.996454] done.
[   31.996992] jffs2: notice: (386) jffs2_build_xattr_subsystem: complete building xattr subsystem, 0 of xdatum (0 unchecked, 0 orphan) and 0 of xref (0 dead, 0 orphan) found.
[   32.014570] mount_root: overlay filesystem has not been fully initialized yet
[   32.486508] mount_root: switching to jffs2 overlay
[  118.362246] urandom-seed: Seed file not found (/etc/urandom.seed)
[  118.629928] procd: - early -
[  118.631489] procd: - watchdog -
[  119.262499] random: jshn: uninitialized urandom read (4 bytes read)
[  119.406133] procd: - watchdog -
[  119.408151] procd: - ubus -
[  119.895864] random: ubusd: uninitialized urandom read (4 bytes read)
[  119.968710] random: jshn: uninitialized urandom read (4 bytes read)
[  119.990443] procd: - init -
[  120.770758] kmodloader: loading kernel modules from /etc/modules.d/*
[  120.815668] random: crng init done
[  120.817628] random: 6 urandom warning(s) missed due to ratelimiting
[  120.888851] tun: Universal TUN/TAP device driver, 1.6
[  120.892452] tun: (C) 1999-2004 Max Krasnyansky <maxk@qualcomm.com>
[  121.147844] i2c /dev entries driver
[  121.185190] hidraw: raw HID events driver (C) Jiri Kosina
[  121.265108] Bluetooth: Core ver 2.22
[  121.267465] NET: Registered protocol family 31
[  121.271663] Bluetooth: HCI device and connection manager initialized
[  121.278054] Bluetooth: HCI socket layer initialized
[  121.282865] Bluetooth: L2CAP socket layer initialized
[  121.287949] Bluetooth: SCO socket layer initialized
[  121.408116] Bluetooth: BNEP (Ethernet Emulation) ver 1.3
[  121.411976] Bluetooth: BNEP filters: protocol multicast
[  121.417293] Bluetooth: BNEP socket layer initialized
[  121.464261] usbcore: registered new interface driver btusb
[  121.479357] usbcore: registered new interface driver cdc_acm
[  121.483566] cdc_acm: USB Abstract Control Model driver for USB modems and ISDN adapters
[  121.537599] Loading modules backported from Linux version wt-2017-11-01-0-gfe248fc2c180
[  121.544154] Backport generated by backports.git v4.14-rc2-1-31-g86cf0e5d
[  121.608152] Bluetooth: HCI UART driver ver 2.3
[  121.611149] Bluetooth: HCI UART protocol H4 registered
[  121.616362] Bluetooth: HCI UART protocol BCSP registered
[  121.658456] Bluetooth: HIDP (Human Interface Emulation) ver 1.2
[  121.663002] Bluetooth: HIDP socket layer initialized
[  121.711070] nf_conntrack version 0.5.0 (1024 buckets, 4096 max)
[  121.949356] Bluetooth: RFCOMM TTY layer initialized
[  121.952816] Bluetooth: RFCOMM socket layer initialized
[  121.958028] Bluetooth: RFCOMM ver 1.11
[  121.969194] usbcore: registered new interface driver usbhid
[  121.973313] usbhid: USB HID core driver
[  122.012161] usbcore: registered new interface driver usbserial
[  122.016807] usbcore: registered new interface driver usbserial_generic
[  122.023178] usbserial: USB Serial support registered for generic
[  122.110169] xt_time: kernel timezone is -0000
[  122.128754] usbcore: registered new interface driver cdc_ether
[  122.199283] usbcore: registered new interface driver ftdi_sio
[  122.203693] usbserial: USB Serial support registered for FTDI USB Serial Device
[  122.238462] ip_tables: (C) 2000-2006 Netfilter Core Team
[  122.265262] usbcore: registered new interface driver keyspan
[  122.269710] usbserial: USB Serial support registered for Keyspan - (without firmware)
[  122.277455] usbserial: USB Serial support registered for Keyspan 1 port adapter
[  122.284682] usbserial: USB Serial support registered for Keyspan 2 port adapter
[  122.292092] usbserial: USB Serial support registered for Keyspan 4 port adapter
[  122.439287] usbcore: registered new interface driver pl2303
[  122.443537] usbserial: USB Serial support registered for pl2303
[  122.449494] pl2303 1-1.1:1.0: pl2303 converter detected
[  122.487591] usb 1-1.1: pl2303 converter now attached to ttyUSB0
[  122.510509] PPP generic driver version 2.4.2
[  122.517507] NET: Registered protocol family 24
[  122.539297] usbcore: registered new interface driver rndis_host
[  122.664137] ath: EEPROM regdomain: 0x0
[  122.664152] ath: EEPROM indicates default country code should be used
[  122.664157] ath: doing EEPROM country->regdmn map search
[  122.664178] ath: country maps to regdmn code: 0x3a
[  122.664186] ath: Country alpha2 being used: US
[  122.664191] ath: Regpair used: 0x3a
[  122.676253] ieee80211 phy0: Selected rate control algorithm 'minstrel_ht'
[  122.682144] ieee80211 phy0: Atheros AR9330 Rev:1 mem=0xb8100000, irq=2
[  122.736189] kmodloader: done loading kernel modules from /etc/modules.d/*
[  142.669702] br-lan: port 1(eth0) entered blocking state
[  142.673490] br-lan: port 1(eth0) entered disabled state
[  142.679280] device eth0 entered promiscuous mode
[  144.324141] ath: EEPROM regdomain: 0x8024
[  144.324156] ath: EEPROM indicates we should expect a country code
[  144.324162] ath: doing EEPROM country->regdmn map search
[  144.324168] ath: country maps to regdmn code: 0x21
[  144.324176] ath: Country alpha2 being used: AU
[  144.324182] ath: Regpair used: 0x21
[  144.324191] ath: regdomain 0x8024 dynamically updated by user
[  149.144801] wlan0: authenticate with 0e:02:8e:95:a3:6a
[  149.160256] wlan0: send auth to 0e:02:8e:95:a3:6a (try 1/3)
[  149.179927] wlan0: authenticated
[  149.205670] wlan0: associate with 0e:02:8e:95:a3:6a (try 1/3)
[  149.234517] wlan0: RX AssocResp from 0e:02:8e:95:a3:6a (capab=0x1431 status=0 aid=1)
[  149.241325] wlan0: associated
[  149.434140] wlan0: Limiting TX power to 30 (30 - 0) dBm as advertised by 0e:02:8e:95:a3:6a

Jeremy-dmesg_reboot.txt

[    0.000000] Linux version 4.9.160 (jeremy@devtest) (gcc version 7.3.0 (OpenWrt GCC 7.3.0 r7405-06a20af) ) #0 Sun Mar 3 17:14:45 2019
[    0.000000] MyLoader: sysp=07c3cb73, boardp=69db762d, parts=24de692d
[    0.000000] bootconsole [early0] enabled
[    0.000000] CPU0 revision is: 00019374 (MIPS 24Kc)
[    0.000000] SoC: Atheros AR9330 rev 1
[    0.000000] Determined physical RAM map:
[    0.000000]  memory: 04000000 @ 00000000 (usable)
[    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] On node 0 totalpages: 16384
[    0.000000] free_area_init_node: node 0, pgdat 804373e4, node_mem_map 81000020
[    0.000000]   Normal zone: 128 pages used for memmap
[    0.000000]   Normal zone: 0 pages reserved
[    0.000000]   Normal zone: 16384 pages, LIFO batch:3
[    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: 16256
[    0.000000] Kernel command line:  board=TL-MR3020  console=ttyATH0,115200 rootfstype=squashfs,jffs2 noinitrd
[    0.000000] PID hash table entries: 256 (order: -2, 1024 bytes)
[    0.000000] Dentry cache hash table entries: 8192 (order: 3, 32768 bytes)
[    0.000000] Inode-cache hash table entries: 4096 (order: 2, 16384 bytes)
[    0.000000] Writing ErrCtl register=00000000
[    0.000000] Readback ErrCtl register=00000000
[    0.000000] Memory: 60100K/65536K available (2991K kernel code, 165K rwdata, 780K rodata, 280K init, 203K bss, 5436K 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] Clocks: CPU:400.000MHz, DDR:400.000MHz, AHB:200.000MHz, Ref:25.000MHz
[    0.000000] clocksource: MIPS: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 9556302233 ns
[    0.000013] sched_clock: 32 bits at 200MHz, resolution 5ns, wraps every 10737418237ns
[    0.007566] Calibrating delay loop... 265.42 BogoMIPS (lpj=1327104)
[    0.088749] pid_max: default: 32768 minimum: 301
[    0.093332] Mount-cache hash table entries: 1024 (order: 0, 4096 bytes)
[    0.099504] Mountpoint-cache hash table entries: 1024 (order: 0, 4096 bytes)
[    0.110139] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[    0.118178] futex hash table entries: 256 (order: -1, 3072 bytes)
[    0.124884] NET: Registered protocol family 16
[    0.130246] MIPS: machine is TP-LINK TL-MR3020
[    0.425535] clocksource: Switched to clocksource MIPS
[    0.430465] NET: Registered protocol family 2
[    0.434404] TCP established hash table entries: 1024 (order: 0, 4096 bytes)
[    0.440018] TCP bind hash table entries: 1024 (order: 0, 4096 bytes)
[    0.446020] TCP: Hash tables configured (established 1024 bind 1024)
[    0.452207] UDP hash table entries: 256 (order: 0, 4096 bytes)
[    0.457698] UDP-Lite hash table entries: 256 (order: 0, 4096 bytes)
[    0.463944] NET: Registered protocol family 1
[    0.467857] PCI: CLS 0 bytes, default 32
[    0.474220] Crashlog allocated RAM at address 0x3f00000
[    0.479476] workingset: timestamp_bits=30 max_order=14 bucket_order=0
[    0.494104] squashfs: version 4.0 (2009/01/31) Phillip Lougher
[    0.498348] jffs2: version 2.2 (NAND) (SUMMARY) (LZMA) (RTIME) (CMODE_PRIORITY) (c) 2001-2006 Red Hat, Inc.
[    0.519971] io scheduler noop registered
[    0.522338] io scheduler deadline registered (default)
[    0.527842] Serial: 8250/16550 driver, 1 ports, IRQ sharing disabled
[    0.533895] ar933x-uart: ttyATH0 at MMIO 0x18020000 (irq = 11, base_baud = 1562500) is a AR933X UART
[    0.542542] console [ttyATH0] enabled
[    0.549346] bootconsole [early0] disabled
[    0.561900] m25p80 spi0.0: found w25q128, expected m25p80
[    0.577396] m25p80 spi0.0: w25q128 (16384 Kbytes)
[    0.581003] 5 tp-link partitions found on MTD device spi0.0
[    0.586240] Creating 5 MTD partitions on "spi0.0":
[    0.590991] 0x000000000000-0x000000020000 : "u-boot"
[    0.598656] 0x000000020000-0x0000001654bc : "kernel"
[    0.605018] 0x0000001654bc-0x000000ff0000 : "rootfs"
[    0.610791] mtd: device 2 (rootfs) set to be root filesystem
[    0.615052] 1 squashfs-split partitions found on MTD device rootfs
[    0.621267] 0x000000700000-0x000000ff0000 : "rootfs_data"
[    0.629543] 0x000000ff0000-0x000001000000 : "art"
[    0.635688] 0x000000020000-0x000000ff0000 : "firmware"
[    0.643620] libphy: Fixed MDIO Bus: probed
[    0.665691] libphy: ag71xx_mdio: probed
[    1.297248] ag71xx ag71xx.0: connected to PHY at ag71xx-mdio.1:04 [uid=004dd041, driver=Generic PHY]
[    1.306021] eth0: Atheros AG71xx at 0xb9000000, irq 4, mode:MII
[    1.311866] NET: Registered protocol family 17
[    1.315457] 8021q: 802.1Q VLAN Support v1.8
[    1.322857] hctosys: unable to open rtc device (rtc0)
[    1.331226] VFS: Mounted root (squashfs filesystem) readonly on device 31:2.
[    1.339057] Freeing unused kernel memory: 280K
[    1.342040] This architecture does not have kernel memory protection.
[    2.210258] init: Console is alive
[    2.212499] init: - watchdog -
[    2.515551] random: fast init done
[    4.271850] kmodloader: loading kernel modules from /etc/modules-boot.d/*
[    4.413935] usbcore: registered new interface driver usbfs
[    4.418170] usbcore: registered new interface driver hub
[    4.423382] usbcore: registered new device driver usb
[    4.433940] ds1302: RTC found.
[    4.436014] rtc_time	: 02:15:16
[    4.436014] rtc_date	: 2019-03-07
[    4.447145] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[    4.470556] ar933x_lcd initialized
[    4.472507] ar933x_lcd: ar933x_lcd device registered with major 251
[    4.491894] SCSI subsystem initialized
[    4.501120] ehci-platform: EHCI generic platform driver
[    4.505042] ehci-platform ehci-platform: EHCI Host Controller
[    4.510750] ehci-platform ehci-platform: new USB bus registered, assigned bus number 1
[    4.520677] ehci-platform ehci-platform: irq 3, io mem 0x1b000000
[    4.545563] ehci-platform ehci-platform: USB 2.0 started, EHCI 1.00
[    4.551643] hub 1-0:1.0: USB hub found
[    4.554553] hub 1-0:1.0: 1 port detected
[    4.565494] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
[    4.572264] ohci-platform: OHCI generic platform driver
[    4.585244] usbcore: registered new interface driver usb-storage
[    4.590752] kmodloader: done loading kernel modules from /etc/modules-boot.d/*
[    4.607664] init: - preinit -
[    5.232300] usb 1-1: new high-speed USB device number 2 using ehci-platform
[    5.473410] hub 1-1:1.0: USB hub found
[    5.476265] hub 1-1:1.0: 4 ports detected
[    5.503546] random: procd: uninitialized urandom read (4 bytes read)
[    5.888796] usb 1-1.1: new full-speed USB device number 3 using ehci-platform
[    5.941434] jffs2: notice: (386) jffs2_build_xattr_subsystem: complete building xattr subsystem, 0 of xdatum (0 unchecked, 0 orphan) and 0 of xref (0 dead, 0 orphan) found.
[    5.957684] mount_root: switching to jffs2 overlay
[    6.017656] urandom-seed: Seeding with /etc/urandom.seed
[    6.300446] procd: - early -
[    6.302003] procd: - watchdog -
[    6.305675] usb 1-1.4: new full-speed USB device number 4 using ehci-platform
[    6.948839] random: jshn: uninitialized urandom read (4 bytes read)
[    7.121850] procd: - watchdog -
[    7.123917] procd: - ubus -
[    7.607238] random: jshn: uninitialized urandom read (4 bytes read)
[    7.626091] random: ubusd: uninitialized urandom read (4 bytes read)
[    7.679879] procd: - init -
[    8.566358] kmodloader: loading kernel modules from /etc/modules.d/*
[    8.761995] tun: Universal TUN/TAP device driver, 1.6
[    8.765675] tun: (C) 1999-2004 Max Krasnyansky <maxk@qualcomm.com>
[    8.798448] i2c /dev entries driver
[    8.832652] hidraw: raw HID events driver (C) Jiri Kosina
[    8.917282] Bluetooth: Core ver 2.22
[    8.919529] NET: Registered protocol family 31
[    8.923834] Bluetooth: HCI device and connection manager initialized
[    8.930254] Bluetooth: HCI socket layer initialized
[    8.935038] Bluetooth: L2CAP socket layer initialized
[    8.940123] Bluetooth: SCO socket layer initialized
[    9.077916] Bluetooth: BNEP (Ethernet Emulation) ver 1.3
[    9.081780] Bluetooth: BNEP filters: protocol multicast
[    9.087087] Bluetooth: BNEP socket layer initialized
[    9.126146] usbcore: registered new interface driver btusb
[    9.138684] usbcore: registered new interface driver cdc_acm
[    9.142891] cdc_acm: USB Abstract Control Model driver for USB modems and ISDN adapters
[    9.167552] Loading modules backported from Linux version wt-2017-11-01-0-gfe248fc2c180
[    9.174145] Backport generated by backports.git v4.14-rc2-1-31-g86cf0e5d
[    9.229966] Bluetooth: HCI UART driver ver 2.3
[    9.232964] Bluetooth: HCI UART protocol H4 registered
[    9.238167] Bluetooth: HCI UART protocol BCSP registered
[    9.275616] Bluetooth: HIDP (Human Interface Emulation) ver 1.2
[    9.280126] Bluetooth: HIDP socket layer initialized
[    9.323704] nf_conntrack version 0.5.0 (1024 buckets, 4096 max)
[    9.515636] Bluetooth: RFCOMM TTY layer initialized
[    9.519104] Bluetooth: RFCOMM socket layer initialized
[    9.524231] Bluetooth: RFCOMM ver 1.11
[    9.560681] usbcore: registered new interface driver usbhid
[    9.564801] usbhid: USB HID core driver
[    9.599379] usbcore: registered new interface driver usbserial
[    9.603887] usbcore: registered new interface driver usbserial_generic
[    9.610494] usbserial: USB Serial support registered for generic
[    9.690669] xt_time: kernel timezone is -0000
[    9.706891] usbcore: registered new interface driver cdc_ether
[    9.789266] usbcore: registered new interface driver ftdi_sio
[    9.793681] usbserial: USB Serial support registered for FTDI USB Serial Device
[    9.828579] ip_tables: (C) 2000-2006 Netfilter Core Team
[    9.855272] usbcore: registered new interface driver keyspan
[    9.859745] usbserial: USB Serial support registered for Keyspan - (without firmware)
[    9.867456] usbserial: USB Serial support registered for Keyspan 1 port adapter
[    9.874721] usbserial: USB Serial support registered for Keyspan 2 port adapter
[    9.882087] usbserial: USB Serial support registered for Keyspan 4 port adapter
[   10.029422] usbcore: registered new interface driver pl2303
[   10.033685] usbserial: USB Serial support registered for pl2303
[   10.039630] pl2303 1-1.1:1.0: pl2303 converter detected
[   10.067838] usb 1-1.1: pl2303 converter now attached to ttyUSB0
[   10.088165] PPP generic driver version 2.4.2
[   10.101462] NET: Registered protocol family 24
[   10.116989] usbcore: registered new interface driver rndis_host
[   10.254213] ath: EEPROM regdomain: 0x0
[   10.254227] ath: EEPROM indicates default country code should be used
[   10.254232] ath: doing EEPROM country->regdmn map search
[   10.254253] ath: country maps to regdmn code: 0x3a
[   10.254261] ath: Country alpha2 being used: US
[   10.254266] ath: Regpair used: 0x3a
[   10.266284] ieee80211 phy0: Selected rate control algorithm 'minstrel_ht'
[   10.272154] ieee80211 phy0: Atheros AR9330 Rev:1 mem=0xb8100000, irq=2
[   10.416726] kmodloader: done loading kernel modules from /etc/modules.d/*
[   28.809704] br-lan: port 1(eth0) entered blocking state
[   28.813495] br-lan: port 1(eth0) entered disabled state
[   28.819309] device eth0 entered promiscuous mode
[   30.478545] ath: EEPROM regdomain: 0x8024
[   30.478559] ath: EEPROM indicates we should expect a country code
[   30.478566] ath: doing EEPROM country->regdmn map search
[   30.478572] ath: country maps to regdmn code: 0x21
[   30.478580] ath: Country alpha2 being used: AU
[   30.478585] ath: Regpair used: 0x21
[   30.478595] ath: regdomain 0x8024 dynamically updated by user
[   35.277039] wlan0: authenticate with 0e:02:8e:95:a3:6a
[   35.292331] wlan0: send auth to 0e:02:8e:95:a3:6a (try 1/3)
[   35.303626] wlan0: authenticated
[   35.345670] wlan0: associate with 0e:02:8e:95:a3:6a (try 1/3)
[   35.438641] wlan0: RX AssocResp from 0e:02:8e:95:a3:6a (capab=0x1431 status=0 aid=1)
[   35.445289] wlan0: associated
[   35.486964] wlan0: Limiting TX power to 30 (30 - 0) dBm as advertised by 0e:02:8e:95:a3:6a
[  102.573864] random: crng init done
[  102.573887] random: 6 urandom warning(s) missed due to rate limiting

Still trying to work out what is happening here. The question boils down to, "what would cause the system to reset to factory default everything in /overlay/upper/etc/ but not /overlay/upper/storage/ (the latter is where our application writes measurement data every minute).

I've gone back to basics starting with the flash memory layout. The diagram at https://openwrt.org/docs/techref/flash.layout makes sense and I can match it to the messages shown by dmesg:

[    0.581037] 5 tp-link partitions found on MTD device spi0.0
[    0.586272] Creating 5 MTD partitions on "spi0.0":
[    0.591027] 0x000000000000-0x000000020000 : "u-boot"
[    0.598690] 0x000000020000-0x0000001654bc : "kernel"
[    0.605052] 0x0000001654bc-0x000000ff0000 : "rootfs"
[    0.610825] mtd: device 2 (rootfs) set to be root filesystem
[    0.615086] 1 squashfs-split partitions found on MTD device rootfs
[    0.621302] 0x000000700000-0x000000ff0000 : "rootfs_data"
[    0.629579] 0x000000ff0000-0x000001000000 : "art"
[    0.635726] 0x000000020000-0x000000ff0000 : "firmware"

But something worries me. If you work out the sizes and starting addresses of each partition shown above, you get:
rootfs is 14890 1K blocks starting at 0x00000016549c,
rootfs_data (/overlay) is 9152 1K blocks starting at 0x000000700000,
and therefore /rom should be 5738 1K blocks (0x700000-0x16549c) starting at 0x00000016549c.
However I see this on the running system:

root@OpenWrt:~# df 
Filesystem           1K-blocks      Used Available Use% Mounted on
/dev/root                 5888      5888         0 100% /rom
tmpfs                    30188       108     30080   0% /tmp
/dev/mtdblock3            9152      1748      7404  19% /overlay
overlayfs:/overlay        9152      1748      7404  19% /
tmpfs                      512         0       512   0% /dev
root@OpenWrt:~# 

i.e. /overlay is the expected size but /rom is 150K bigger than the partition table says it should be. How can this happen?

Thanks.

I’m not sure how df handles it when the file system employs compression and de-duping.

I think you're right, Jeff. Previous versions of our firmware (which work fine) also have /rom being larger than the space implied by the partition layout.

1 Like

Fixed by the patch described in Fix no settings saved which enforces the use of the flash's SPI bus interface for all reads.

(I suspected that the flash chip had trouble handling the sustained high write rate incurred while restoring from the backup created immediately before the firmware update. What the patch shows is that it's the way OpenWrt accesses the flash that's causing the problem. For an OpenWrt install with a small amount of configuration data to restore the flash was probably updating only one or maybe two pages of memory. For our application with a few MB to restore the flash would be updating many pages of memory and this is where the memory-mapped access preferred by the OpenWrt MTD driver was getting it wrong.)

There is another way to solve this problem, which is to read more than 32 bytes of data at a time without any caching problems, which I explain here

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