USB Port hard down with Error 145

First, many thanks for developing a very cool product to fill a unique need.

I am attempting to use VH with a GL-AR300M16 to remotely program a two-way radio. The initial connection seems normal and programming goes on without a hitch. The trouble starts when the device reboots after the programming process completes. The USB port is unresponsive until the GLiNET box is fully reset. This operation has been run with both mobile and portable versions of the radio. The mobile radio will reconnect to the USB port about 50% of the time or better. The portable radio however fails to reconnect every time. I have tried the multiple Auto Use options including Device, Port and Device/Port. I have also tried various settings for reconnect delay timers. Not sure what to try next. Please see attached server logs. Thanks for any direction you can provide. 

The log file down to 13:15:23 is with a mobile radio connected. Below that (and highlighted in Bold) at the bottom of the log is the portable radio.

Fri Sep 16 14:06:57 2022 kern.notice kernel: [    0.000000] Linux version 5.10.134 (root@ubuntu) (mips-openwrt-linux-musl-gcc (OpenWrt GCC 11.2.0 r19590-042d558536) 11.2.0, GNU ld (GNU Binutils) 2.37) #0 Sun Jul 31 15:12:47 2022
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] printk: bootconsole [early0] enabled
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] CPU0 revision is: 00019374 (MIPS 24Kc)
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] MIPS: machine is GL.iNet GL-AR300M16
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] SoC: Qualcomm Atheros QCA9533 ver 2 rev 0
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] Initrd not found or empty - disabling initrd
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] Primary instruction cache 64kB, VIPT, 4-way, linesize 32 bytes.
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] Primary data cache 32kB, 4-way, VIPT, cache aliases, linesize 32 bytes
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] Zone ranges:
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000]   Normal   [mem 0x0000000000000000-0x0000000007ffffff]
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] Movable zone start for each node
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] Early memory node ranges
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000]   node   0: [mem 0x0000000000000000-0x0000000007ffffff]
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] Initmem setup node 0 [mem 0x0000000000000000-0x0000000007ffffff]
Fri Sep 16 14:06:57 2022 kern.debug kernel: [    0.000000] On node 0 totalpages: 32768
Fri Sep 16 14:06:57 2022 kern.debug kernel: [    0.000000]   Normal zone: 256 pages used for memmap
Fri Sep 16 14:06:57 2022 kern.debug kernel: [    0.000000]   Normal zone: 0 pages reserved
Fri Sep 16 14:06:57 2022 kern.debug kernel: [    0.000000]   Normal zone: 32768 pages, LIFO batch:7
Fri Sep 16 14:06:57 2022 kern.debug kernel: [    0.000000] pcpu-alloc: s0 r0 d32768 u32768 alloc=1*32768
Fri Sep 16 14:06:57 2022 kern.debug kernel: [    0.000000] pcpu-alloc: [0] 0
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 32512
Fri Sep 16 14:06:57 2022 kern.notice kernel: [    0.000000] Kernel command line: console=ttyS0,115200n8 rootfstype=squashfs,jffs2
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] Dentry cache hash table entries: 16384 (order: 4, 65536 bytes, linear)
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] Inode-cache hash table entries: 8192 (order: 3, 32768 bytes, linear)
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] Writing ErrCtl register=00000000
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] Readback ErrCtl register=00000000
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] Memory: 121620K/131072K available (5090K kernel code, 578K rwdata, 1152K rodata, 1236K init, 194K bss, 9452K reserved, 0K cma-reserved)
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] SLUB: HWalign=32, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] NR_IRQS: 51
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] CPU clock: 650.000 MHz
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] clocksource: MIPS: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 5880801374 ns
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000009] sched_clock: 32 bits at 325MHz, resolution 3ns, wraps every 6607641598ns
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.008300] Calibrating delay loop... 432.53 BogoMIPS (lpj=2162688)
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.074928] pid_max: default: 32768 minimum: 301
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.079949] Mount-cache hash table entries: 1024 (order: 0, 4096 bytes, linear)
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.087651] Mountpoint-cache hash table entries: 1024 (order: 0, 4096 bytes, linear)
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.097646] dyndbg: Ignore empty _ddebug table in a CONFIG_DYNAMIC_DEBUG_CORE build
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.108188] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.118602] futex hash table entries: 256 (order: -1, 3072 bytes, linear)
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.125820] pinctrl core: initialized pinctrl subsystem
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.132947] NET: Registered protocol family 16
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.191484] i2c-gpio i2c: using lines 17 (SDA) and 16 (SCL)
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.204360] clocksource: Switched to clocksource MIPS
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.210844] NET: Registered protocol family 2
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.215766] IP idents hash table entries: 2048 (order: 2, 16384 bytes, linear)
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.224044] tcp_listen_portaddr_hash hash table entries: 512 (order: 0, 4096 bytes, linear)
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.232943] TCP established hash table entries: 1024 (order: 0, 4096 bytes, linear)
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.241038] TCP bind hash table entries: 1024 (order: 0, 4096 bytes, linear)
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.248490] TCP: Hash tables configured (established 1024 bind 1024)
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.255356] UDP hash table entries: 256 (order: 0, 4096 bytes, linear)
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.262269] UDP-Lite hash table entries: 256 (order: 0, 4096 bytes, linear)
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.269983] NET: Registered protocol family 1
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.274652] PCI: CLS 0 bytes, default 32
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.284764] workingset: timestamp_bits=30 max_order=15 bucket_order=0
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.295239] squashfs: version 4.0 (2009/01/31) Phillip Lougher
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.301393] jffs2: version 2.2 (NAND) (SUMMARY) (LZMA) (RTIME) (CMODE_PRIORITY) (c) 2001-2006 Red Hat, Inc.
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.315980] pinctrl-single 1804002c.pinmux: 576 pins, size 72
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.323134] Serial: 8250/16550 driver, 1 ports, IRQ sharing disabled
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.330640] printk: console [ttyS0] disabled
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.335289] 18020000.uart: ttyS0 at MMIO 0x18020000 (irq = 9, base_baud = 1562500) is a 16550A
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.344415] printk: console [ttyS0] enabled
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.353464] printk: bootconsole [early0] disabled
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.374119] spi-nor spi0.0: w25q128 (16384 Kbytes)
Fri Sep 16 14:06:57 2022 kern.notice kernel: [    0.379194] 4 fixed-partitions partitions found on MTD device spi0.0
Fri Sep 16 14:06:57 2022 kern.notice kernel: [    0.385783] Creating 4 MTD partitions on "spi0.0":
Fri Sep 16 14:06:57 2022 kern.notice kernel: [    0.390739] 0x000000000000-0x000000040000 : "u-boot"
Fri Sep 16 14:06:57 2022 kern.notice kernel: [    0.399366] 0x000000040000-0x000000050000 : "u-boot-env"
Fri Sep 16 14:06:57 2022 kern.notice kernel: [    0.405934] 0x000000050000-0x000000ff0000 : "firmware"
Fri Sep 16 14:06:57 2022 kern.notice kernel: [    0.413833] 2 uimage-fw partitions found on MTD device firmware
Fri Sep 16 14:06:57 2022 kern.notice kernel: [    0.420025] Creating 2 MTD partitions on "firmware":
Fri Sep 16 14:06:57 2022 kern.notice kernel: [    0.425170] 0x000000000000-0x000000210000 : "kernel"
Fri Sep 16 14:06:57 2022 kern.notice kernel: [    0.431999] 0x000000210000-0x000000fa0000 : "rootfs"
Fri Sep 16 14:06:57 2022 kern.notice kernel: [    0.438116] mtd: device 4 (rootfs) set to be root filesystem
Fri Sep 16 14:06:57 2022 kern.notice kernel: [    0.444961] 1 squashfs-split partitions found on MTD device rootfs
Fri Sep 16 14:06:57 2022 kern.notice kernel: [    0.451367] 0x0000004a0000-0x000000fa0000 : "rootfs_data"
Fri Sep 16 14:06:57 2022 kern.notice kernel: [    0.457940] 0x000000ff0000-0x000001000000 : "art"
Fri Sep 16 14:06:57 2022 kern.err kernel: [    0.845454] ag71xx 19000000.eth: Could not connect to PHY device. Deferring probe.
Fri Sep 16 14:06:57 2022 kern.info kernel: [    1.538078] switch0: Atheros AR8229 rev. 1 switch registered on mdio.0
Fri Sep 16 14:06:57 2022 kern.info kernel: [    1.596381] ag71xx 1a000000.eth: connected to PHY at fixed-0:00 [uid=00000000, driver=Generic PHY]
Fri Sep 16 14:06:57 2022 kern.info kernel: [    1.606351] eth0: Atheros AG71xx at 0xba000000, irq 5, mode: gmii
Fri Sep 16 14:06:57 2022 kern.info kernel: [    1.612879] i2c /dev entries driver
Fri Sep 16 14:06:57 2022 kern.info kernel: [    1.618554] NET: Registered protocol family 10
Fri Sep 16 14:06:57 2022 kern.info kernel: [    1.630458] Segment Routing with IPv6
Fri Sep 16 14:06:57 2022 kern.info kernel: [    1.634422] NET: Registered protocol family 17
Fri Sep 16 14:06:57 2022 kern.info kernel: [    1.639070] 8021q: 802.1Q VLAN Support v1.8
Fri Sep 16 14:06:57 2022 kern.info kernel: [    1.644178] PCI host bridge /ahb/pcie-controller@180c0000 ranges:
Fri Sep 16 14:06:57 2022 kern.info kernel: [    1.650578]  MEM 0x0000000010000000..0x0000000013ffffff
Fri Sep 16 14:06:57 2022 kern.info kernel: [    1.655988]   IO 0x0000000000000000..0x0000000000000000
Fri Sep 16 14:06:57 2022 kern.warn kernel: [    1.661391] ar724x-pci 180c0000.pcie-controller: PCIe link is down
Fri Sep 16 14:06:57 2022 kern.info kernel: [    1.667999] PCI host bridge to bus 0000:00
Fri Sep 16 14:06:57 2022 kern.info kernel: [    1.672247] pci_bus 0000:00: root bus resource [mem 0x10000000-0x13ffffff]
Fri Sep 16 14:06:57 2022 kern.info kernel: [    1.679374] pci_bus 0000:00: root bus resource [io  0x0000]
Fri Sep 16 14:06:57 2022 kern.info kernel: [    1.685143] pci_bus 0000:00: root bus resource [??? 0x00000000 flags 0x0]
Fri Sep 16 14:06:57 2022 kern.info kernel: [    1.692156] pci_bus 0000:00: No busn resource found for root bus, will use [bus 00-ff]
Fri Sep 16 14:06:57 2022 kern.info kernel: [    1.701177] pci_bus 0000:00: busn_res: [bus 00-ff] end is updated to 00
Fri Sep 16 14:06:57 2022 kern.info kernel: [    2.046461] ag71xx 19000000.eth: connected to PHY at mdio.0:1f:04 [uid=004dd042, driver=Generic PHY]
Fri Sep 16 14:06:57 2022 kern.info kernel: [    2.056844] eth1: Atheros AG71xx at 0xb9000000, irq 4, mode: mii
Fri Sep 16 14:06:57 2022 kern.info kernel: [    2.074269] VFS: Mounted root (squashfs filesystem) readonly on device 31:4.
Fri Sep 16 14:06:57 2022 kern.info kernel: [    2.089218] Freeing unused kernel memory: 1236K
Fri Sep 16 14:06:57 2022 kern.warn kernel: [    2.093900] This architecture does not have kernel memory protection.
Fri Sep 16 14:06:57 2022 kern.info kernel: [    2.100585] Run /sbin/init as init process
Fri Sep 16 14:06:57 2022 kern.debug kernel: [    2.104826]   with arguments:
Fri Sep 16 14:06:57 2022 kern.debug kernel: [    2.104831]     /sbin/init
Fri Sep 16 14:06:57 2022 kern.debug kernel: [    2.104835]   with environment:
Fri Sep 16 14:06:57 2022 kern.debug kernel: [    2.104840]     HOME=/
Fri Sep 16 14:06:57 2022 kern.debug kernel: [    2.104844]     TERM=linux
Fri Sep 16 14:06:57 2022 user.info kernel: [    2.884681] init: Console is alive
Fri Sep 16 14:06:57 2022 user.info kernel: [    2.888721] init: - watchdog -
Fri Sep 16 14:06:57 2022 user.info kernel: [    4.163172] kmodloader: loading kernel modules from /etc/modules-boot.d/*
Fri Sep 16 14:06:57 2022 kern.info kernel: [    4.290387] usbcore: registered new interface driver usbfs
Fri Sep 16 14:06:57 2022 kern.info kernel: [    4.296188] usbcore: registered new interface driver hub
Fri Sep 16 14:06:57 2022 kern.info kernel: [    4.301765] usbcore: registered new device driver usb
Fri Sep 16 14:06:57 2022 kern.info kernel: [    4.315982] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
Fri Sep 16 14:06:57 2022 kern.info kernel: [    4.325974] ehci-fsl: Freescale EHCI Host controller driver
Fri Sep 16 14:06:57 2022 kern.info kernel: [    4.333656] ehci-platform: EHCI generic platform driver
Fri Sep 16 14:06:57 2022 kern.info kernel: [    4.339510] ehci-platform 1b000000.usb: EHCI Host Controller
Fri Sep 16 14:06:57 2022 kern.info kernel: [    4.345435] ehci-platform 1b000000.usb: new USB bus registered, assigned bus number 1
Fri Sep 16 14:06:57 2022 kern.info kernel: [    4.353660] ehci-platform 1b000000.usb: irq 3, io mem 0x1b000000
Fri Sep 16 14:06:57 2022 kern.info kernel: [    4.384383] ehci-platform 1b000000.usb: USB 2.0 started, EHCI 1.00
Fri Sep 16 14:06:57 2022 kern.info kernel: [    4.391722] hub 1-0:1.0: USB hub found
Fri Sep 16 14:06:57 2022 kern.info kernel: [    4.396438] hub 1-0:1.0: 1 port detected
Fri Sep 16 14:06:57 2022 user.info kernel: [    4.404615] kmodloader: done loading kernel modules from /etc/modules-boot.d/*
Fri Sep 16 14:06:57 2022 user.info kernel: [    4.422739] init: - preinit -
Fri Sep 16 14:06:57 2022 kern.notice kernel: [    5.653226] random: jshn: uninitialized urandom read (4 bytes read)
Fri Sep 16 14:06:57 2022 kern.notice kernel: [    5.811440] random: jshn: uninitialized urandom read (4 bytes read)
Fri Sep 16 14:06:57 2022 kern.notice kernel: [    5.870205] random: jshn: uninitialized urandom read (4 bytes read)
Fri Sep 16 14:06:57 2022 kern.info kernel: [    6.153927] eth0: link up (1000Mbps/Full duplex)
Fri Sep 16 14:06:57 2022 kern.info kernel: [    6.164464] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
Fri Sep 16 14:06:57 2022 kern.notice kernel: [   10.497283] jffs2: notice: (486) jffs2_build_xattr_subsystem: complete building xattr subsystem, 39 of xdatum (8 unchecked, 31 orphan) and 41 of xref (31 dead, 0 orphan) found.
Fri Sep 16 14:06:57 2022 user.info kernel: [   10.515752] mount_root: switching to jffs2 overlay
Fri Sep 16 14:06:57 2022 kern.warn kernel: [   10.523219] overlayfs: upper fs does not support tmpfile.
Fri Sep 16 14:06:57 2022 user.warn kernel: [   10.537741] urandom-seed: Seeding with /etc/urandom.seed
Fri Sep 16 14:06:57 2022 kern.info kernel: [   10.658904] eth0: link down
Fri Sep 16 14:06:57 2022 user.info kernel: [   10.675888] procd: - early -
Fri Sep 16 14:06:57 2022 user.info kernel: [   10.679247] procd: - watchdog -
Fri Sep 16 14:06:57 2022 user.info kernel: [   11.393235] procd: - watchdog -
Fri Sep 16 14:06:57 2022 user.info kernel: [   11.503019] procd: - ubus -
Fri Sep 16 14:06:57 2022 kern.notice kernel: [   11.723649] random: ubusd: uninitialized urandom read (4 bytes read)
Fri Sep 16 14:06:57 2022 kern.notice kernel: [   11.732765] random: ubusd: uninitialized urandom read (4 bytes read)
Fri Sep 16 14:06:57 2022 kern.notice kernel: [   11.739989] random: ubusd: uninitialized urandom read (4 bytes read)
Fri Sep 16 14:06:57 2022 user.info kernel: [   11.750217] procd: - init -
Fri Sep 16 14:06:57 2022 kern.notice kernel: [   12.810789] random: jshn: uninitialized urandom read (4 bytes read)
Fri Sep 16 14:06:57 2022 kern.notice kernel: [   12.861507] random: ubusd: uninitialized urandom read (4 bytes read)
Fri Sep 16 14:06:57 2022 kern.notice kernel: [   12.894701] random: ubus: uninitialized urandom read (4 bytes read)
Fri Sep 16 14:06:57 2022 user.info kernel: [   12.923505] kmodloader: loading kernel modules from /etc/modules.d/*
Fri Sep 16 14:06:57 2022 kern.info kernel: [   13.494719] Loading modules backported from Linux version v5.15.58-0-g7d8048d4e064
Fri Sep 16 14:06:57 2022 kern.info kernel: [   13.502552] Backport generated by backports.git v5.15.58-1-0-g42a95ce7
Fri Sep 16 14:06:57 2022 kern.info kernel: [   13.575761] xt_time: kernel timezone is -0000
Fri Sep 16 14:06:57 2022 user.info kernel: [   13.593698] urngd: v1.0.2 started.
Fri Sep 16 14:06:57 2022 kern.debug kernel: [   13.794337] ath: EEPROM regdomain: 0x0
Fri Sep 16 14:06:57 2022 kern.debug kernel: [   13.794411] ath: EEPROM indicates default country code should be used
Fri Sep 16 14:06:57 2022 kern.debug kernel: [   13.794416] ath: doing EEPROM country->regdmn map search
Fri Sep 16 14:06:57 2022 kern.debug kernel: [   13.794434] ath: country maps to regdmn code: 0x3a
Fri Sep 16 14:06:57 2022 kern.debug kernel: [   13.794441] ath: Country alpha2 being used: US
Fri Sep 16 14:06:57 2022 kern.debug kernel: [   13.794446] ath: Regpair used: 0x3a
Fri Sep 16 14:06:57 2022 kern.debug kernel: [   13.806923] ieee80211 phy0: Selected rate control algorithm 'minstrel_ht'
Fri Sep 16 14:06:57 2022 kern.info kernel: [   13.809203] ieee80211 phy0: Atheros AR9531 Rev:2 mem=0xb8100000, irq=13
Fri Sep 16 14:06:57 2022 user.info kernel: [   13.944854] kmodloader: done loading kernel modules from /etc/modules.d/*
Fri Sep 16 14:06:57 2022 kern.notice kernel: [   14.433111] random: crng init done
Fri Sep 16 14:06:57 2022 kern.notice kernel: [   14.436680] random: 23 urandom warning(s) missed due to ratelimiting
Fri Sep 16 14:06:58 2022 authpriv.info dropbear[890]: Not backgrounding
Fri Sep 16 14:06:59 2022 daemon.notice wpa_supplicant[942]: Successfully initialized wpa_supplicant
Fri Sep 16 14:07:00 2022 user.notice : Added device handler type: bonding
Fri Sep 16 14:07:00 2022 user.notice : Added device handler type: 8021ad
Fri Sep 16 14:07:00 2022 user.notice : Added device handler type: 8021q
Fri Sep 16 14:07:00 2022 user.notice : Added device handler type: macvlan
Fri Sep 16 14:07:00 2022 user.notice : Added device handler type: veth
Fri Sep 16 14:07:00 2022 user.notice : Added device handler type: bridge
Fri Sep 16 14:07:00 2022 user.notice : Added device handler type: Network device
Fri Sep 16 14:07:00 2022 user.notice : Added device handler type: tunnel
Fri Sep 16 14:07:01 2022 daemon.notice procd: /etc/rc.d/S96led: setting up led LAN
Fri Sep 16 14:07:04 2022 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?
Fri Sep 16 14:07:04 2022 kern.info kernel: [   23.667333] eth0: link up (1000Mbps/Full duplex)
Fri Sep 16 14:07:04 2022 kern.info kernel: [   23.684915] br-lan: port 1(eth0) entered blocking state
Fri Sep 16 14:07:04 2022 kern.info kernel: [   23.690337] br-lan: port 1(eth0) entered disabled state
Fri Sep 16 14:07:04 2022 kern.info kernel: [   23.696118] device eth0 entered promiscuous mode
Fri Sep 16 14:07:04 2022 kern.info kernel: [   23.715217] br-lan: port 1(eth0) entered blocking state
Fri Sep 16 14:07:04 2022 kern.info kernel: [   23.720633] br-lan: port 1(eth0) entered forwarding state
Fri Sep 16 14:07:04 2022 daemon.notice netifd: Interface 'lan' is enabled
Fri Sep 16 14:07:04 2022 daemon.notice netifd: Interface 'lan' is setting up now
Fri Sep 16 14:07:04 2022 daemon.notice netifd: Interface 'lan' is now up
Fri Sep 16 14:07:04 2022 daemon.notice netifd: bridge 'br-lan' link is up
Fri Sep 16 14:07:04 2022 daemon.notice netifd: Interface 'lan' has link connectivity
Fri Sep 16 14:07:04 2022 daemon.notice netifd: Interface 'loopback' is enabled
Fri Sep 16 14:07:04 2022 daemon.notice netifd: Interface 'loopback' is setting up now
Fri Sep 16 14:07:04 2022 daemon.notice netifd: Interface 'loopback' is now up
Fri Sep 16 14:07:04 2022 daemon.notice netifd: Interface 'wan' is enabled
Fri Sep 16 14:07:04 2022 daemon.notice netifd: Interface 'wan6' is enabled
Fri Sep 16 14:07:04 2022 daemon.notice netifd: Network device 'eth0' link is up
Fri Sep 16 14:07:04 2022 daemon.notice netifd: Network device 'lo' link is up
Fri Sep 16 14:07:04 2022 daemon.notice netifd: Interface 'loopback' has link connectivity
Fri Sep 16 14:07:05 2022 kern.info kernel: [   24.664530] IPv6: ADDRCONF(NETDEV_CHANGE): br-lan: link becomes ready
Fri Sep 16 14:07:07 2022 daemon.notice netifd: radio0 (1215): sh: out of range
Fri Sep 16 14:07:07 2022 daemon.info procd: - init complete -
Fri Sep 16 14:07:07 2022 kern.warn kernel: [   26.563267] process '/root/vhusbdchglar300m16' started with executable stack
Fri Sep 16 14:07:08 2022 user.info vhusbdchglar300m16[1474]: >>> Starting VirtualHere USB Server v4.4.2 (Built: Aug 16 2022, 18:44:22)<<<
Fri Sep 16 14:07:08 2022 user.info vhusbdchglar300m16[1474]: Using configuration /root/config.ini
Fri Sep 16 14:07:08 2022 daemon.notice netifd: Wireless device 'radio0' is now up
Fri Sep 16 14:07:08 2022 daemon.notice netifd: Interface 'wwlan' is enabled
Fri Sep 16 14:07:08 2022 user.info vhusbdchglar300m16[1474]: Server licensed to=unlicensed max_devices=1
Fri Sep 16 14:07:08 2022 user.info vhusbdchglar300m16[1474]: Using large URB's
Fri Sep 16 14:07:08 2022 user.info vhusbdchglar300m16[1474]: Listening on all network interfaces at TCP port 7575
Fri Sep 16 14:07:09 2022 daemon.notice wpa_supplicant[942]: wlan0: SME: Trying to authenticate with de:71:96:21:17:90 (SSID='PolkRM' freq=2437 MHz)
Fri Sep 16 14:07:09 2022 kern.info kernel: [   28.695484] wlan0: authenticate with de:71:96:21:17:90
Fri Sep 16 14:07:09 2022 kern.info kernel: [   28.714349] wlan0: send auth to de:71:96:21:17:90 (try 1/3)
Fri Sep 16 14:07:09 2022 daemon.notice wpa_supplicant[942]: wlan0: Trying to associate with de:71:96:21:17:90 (SSID='PolkRM' freq=2437 MHz)
Fri Sep 16 14:07:09 2022 kern.info kernel: [   28.763891] wlan0: authenticated
Fri Sep 16 14:07:09 2022 kern.info kernel: [   28.774691] wlan0: associate with de:71:96:21:17:90 (try 1/3)
Fri Sep 16 14:07:09 2022 daemon.notice wpa_supplicant[942]: wlan0: Associated with de:71:96:21:17:90
Fri Sep 16 14:07:09 2022 daemon.notice netifd: Network device 'wlan0' link is up
Fri Sep 16 14:07:09 2022 daemon.notice netifd: Interface 'wwlan' has link connectivity
Fri Sep 16 14:07:09 2022 daemon.notice netifd: Interface 'wwlan' is setting up now
Fri Sep 16 14:07:09 2022 kern.info kernel: [   28.858340] wlan0: RX AssocResp from de:71:96:21:17:90 (capab=0x8731 status=0 aid=2)
Fri Sep 16 14:07:09 2022 kern.info kernel: [   28.866622] wlan0: associated
Fri Sep 16 14:07:09 2022 daemon.notice wpa_supplicant[942]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
Fri Sep 16 14:07:09 2022 daemon.notice wpa_supplicant[942]: wlan0: Unknown event 37
Fri Sep 16 14:07:10 2022 daemon.notice netifd: wwlan (1538): udhcpc: started, v1.35.0
Fri Sep 16 14:07:10 2022 daemon.notice wpa_supplicant[942]: wlan0: WPA: Key negotiation completed with de:71:96:21:17:90 [PTK=CCMP GTK=CCMP]
Fri Sep 16 14:07:10 2022 daemon.notice wpa_supplicant[942]: wlan0: CTRL-EVENT-CONNECTED - Connection to de:71:96:21:17:90 completed [id=0 id_str=]
Fri Sep 16 14:07:10 2022 daemon.notice wpa_supplicant[942]: wlan0: Unknown event 37
Fri Sep 16 14:07:10 2022 kern.info kernel: [   29.231512] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
Fri Sep 16 14:07:10 2022 daemon.notice netifd: wwlan (1538): udhcpc: broadcasting discover
Fri Sep 16 14:07:10 2022 daemon.notice netifd: wwlan (1538): udhcpc: broadcasting select for 192.168.137.92, server 192.168.137.1
Fri Sep 16 14:07:10 2022 daemon.notice netifd: wwlan (1538): udhcpc: lease of 192.168.137.92 obtained from 192.168.137.1, lease time 604800
Fri Sep 16 14:07:10 2022 daemon.notice netifd: Interface 'wwlan' is now up
Fri Sep 16 14:07:13 2022 kern.info kernel: [   32.534386] usb 1-1: new full-speed USB device number 2 using ehci-platform
Fri Sep 16 14:07:13 2022 user.info vhusbdchglar300m16[1474]: Found Full speed device [0cad:101a] "Motorola Solutions, Inc., Motorola APX Series Control Head" at address 11
Fri Oct 14 12:11:17 2022 user.info vhusbdchglar300m16[1474]: 192.168.137.1 connected as connection 1
Fri Oct 14 12:11:17 2022 kern.info kernel: [   41.234388] usb 1-1: reset full-speed USB device number 2 using ehci-platform
Fri Oct 14 12:11:17 2022 user.info vhusbdchglar300m16[1474]: Device 11 [0cad:101a] BOUND to connection 1
Fri Oct 14 12:11:17 2022 kern.info kernel: [   41.794392] usb 1-1: reset full-speed USB device number 2 using ehci-platform
Fri Oct 14 12:11:35 2022 user.info vhusbdchglar300m16[1474]: Device 11 [0cad:101a] UNBOUND from connection 1
Fri Oct 14 12:11:35 2022 kern.warn kernel: [   59.572237] usb 1-1: usbfs: process 1623 (vhusbdchglar300) did not claim interface 1 before use
Fri Oct 14 12:19:06 2022 user.info vhusbdchglar300m16[1474]: Remote Admin script sent to client at 192.168.137.1
Fri Oct 14 12:19:49 2022 user.info vhusbdchglar300m16[1474]: Remote Admin script sent to client at 192.168.137.1
Fri Oct 14 12:21:00 2022 user.info vhusbdchglar300m16[1474]: Remote Admin script sent to client at 192.168.137.1
Fri Oct 14 12:25:47 2022 kern.info kernel: [  911.681623] usb 1-1: reset full-speed USB device number 2 using ehci-platform
Fri Oct 14 12:25:48 2022 user.info vhusbdchglar300m16[1474]: Device 11 [0cad:101a] BOUND to connection 1
Fri Oct 14 12:25:48 2022 kern.info kernel: [  912.251620] usb 1-1: reset full-speed USB device number 2 using ehci-platform
Fri Oct 14 12:26:34 2022 user.info vhusbdchglar300m16[1474]: Remote Admin script sent to client at 192.168.137.1
Fri Oct 14 12:31:56 2022 kern.info kernel: [ 1280.804132] usb 1-1: USB disconnect, device number 2
Fri Oct 14 12:31:56 2022 user.info vhusbdchglar300m16[1474]: Device 11 [0cad:101a] SURPRISE UNBOUND from connection 1
Fri Oct 14 12:31:56 2022 user.info vhusbdchglar300m16[1474]: Unmanaging device 11 [0cad:101a]
Fri Oct 14 12:32:09 2022 kern.info kernel: [ 1293.301597] usb 1-1: new full-speed USB device number 3 using ehci-platform
Fri Oct 14 12:32:09 2022 user.info vhusbdchglar300m16[1474]: Found Full speed device [0cad:101a] "Motorola Solutions, Inc., Motorola APX Series Control Head" at address 11
Fri Oct 14 12:32:09 2022 kern.info kernel: [ 1293.671598] usb 1-1: reset full-speed USB device number 3 using ehci-platform
Fri Oct 14 12:32:10 2022 user.info vhusbdchglar300m16[1474]: Device 11 [0cad:101a] BOUND to connection 1
Fri Oct 14 12:32:10 2022 kern.info kernel: [ 1294.251603] usb 1-1: reset full-speed USB device number 3 using ehci-platform
Fri Oct 14 12:32:57 2022 kern.info kernel: [ 1341.121370] usb 1-1: USB disconnect, device number 3
Fri Oct 14 12:32:57 2022 user.info vhusbdchglar300m16[1474]: Device 11 [0cad:101a] SURPRISE UNBOUND from connection 1
Fri Oct 14 12:32:57 2022 user.info vhusbdchglar300m16[1474]: Unmanaging device 11 [0cad:101a]
Fri Oct 14 12:33:09 2022 kern.info kernel: [ 1353.651590] usb 1-1: new full-speed USB device number 4 using ehci-platform
Fri Oct 14 12:33:10 2022 user.info vhusbdchglar300m16[1474]: Found Full speed device [0cad:101a] "Motorola Solutions, Inc., Motorola APX Series Control Head" at address 11
Fri Oct 14 12:33:10 2022 kern.info kernel: [ 1354.041633] usb 1-1: reset full-speed USB device number 4 using ehci-platform
Fri Oct 14 12:33:10 2022 user.info vhusbdchglar300m16[1474]: Device 11 [0cad:101a] BOUND to connection 1
Fri Oct 14 12:33:10 2022 kern.info kernel: [ 1354.611592] usb 1-1: reset full-speed USB device number 4 using ehci-platform
Fri Oct 14 12:34:00 2022 kern.info kernel: [ 1404.204853] usb 1-1: USB disconnect, device number 4
Fri Oct 14 12:34:00 2022 user.info vhusbdchglar300m16[1474]: Device 11 [0cad:101a] SURPRISE UNBOUND from connection 1
Fri Oct 14 12:34:00 2022 user.info vhusbdchglar300m16[1474]: Unmanaging device 11 [0cad:101a]
Fri Oct 14 12:34:12 2022 kern.info kernel: [ 1416.811604] usb 1-1: new full-speed USB device number 5 using ehci-platform
Fri Oct 14 12:34:13 2022 user.info vhusbdchglar300m16[1474]: Found Full speed device [0cad:101a] "Motorola Solutions, Inc., Motorola APX Series Control Head" at address 11
Fri Oct 14 12:34:13 2022 kern.info kernel: [ 1417.181589] usb 1-1: reset full-speed USB device number 5 using ehci-platform
Fri Oct 14 12:34:13 2022 user.info vhusbdchglar300m16[1474]: Device 11 [0cad:101a] BOUND to connection 1
Fri Oct 14 12:34:13 2022 kern.info kernel: [ 1417.761591] usb 1-1: reset full-speed USB device number 5 using ehci-platform
Fri Oct 14 12:53:17 2022 kern.info kernel: [ 2560.899653] usb 1-1: USB disconnect, device number 5
Fri Oct 14 12:53:17 2022 user.info vhusbdchglar300m16[1474]: Device 11 [0cad:101a] SURPRISE UNBOUND from connection 1
Fri Oct 14 12:53:17 2022 user.info vhusbdchglar300m16[1474]: Unmanaging device 11 [0cad:101a]
Fri Oct 14 12:54:08 2022 kern.info kernel: [ 2612.671530] usb 1-1: new full-speed USB device number 6 using ehci-platform
Fri Oct 14 12:54:09 2022 kern.err kernel: [ 2612.921510] usb 1-1: device descriptor read/64, error -71
Fri Oct 14 12:54:10 2022 kern.info kernel: [ 2614.351521] usb 1-1: new full-speed USB device number 7 using ehci-platform
Fri Oct 14 12:54:10 2022 user.info vhusbdchglar300m16[1474]: Found Full speed device [0cad:1000] "Motorola, CH FLASHZAP" at address 11
Fri Oct 14 13:00:18 2022 user.info vhusbdchglar300m16[1474]: Unmanaging device 11 [0cad:1000]
Fri Oct 14 13:00:18 2022 kern.info kernel: [ 2982.657294] usb 1-1: USB disconnect, device number 7
Fri Oct 14 13:00:30 2022 kern.info kernel: [ 2994.321503] usb 1-1: new full-speed USB device number 8 using ehci-platform
Fri Oct 14 13:00:30 2022 user.info vhusbdchglar300m16[1474]: Found Full speed device [0cad:101a] "Motorola Solutions, Inc., Motorola APX Series Control Head" at address 11
Fri Oct 14 13:00:30 2022 kern.info kernel: [ 2994.691497] usb 1-1: reset full-speed USB device number 8 using ehci-platform
Fri Oct 14 13:00:31 2022 user.info vhusbdchglar300m16[1474]: Device 11 [0cad:101a] BOUND to connection 1
Fri Oct 14 13:00:31 2022 kern.info kernel: [ 2995.241496] usb 1-1: reset full-speed USB device number 8 using ehci-platform
Fri Oct 14 13:02:50 2022 kern.info kernel: [ 3134.671979] usb 1-1: USB disconnect, device number 8
Fri Oct 14 13:02:50 2022 user.info vhusbdchglar300m16[1474]: Device 11 [0cad:101a] SURPRISE UNBOUND from connection 1
Fri Oct 14 13:02:50 2022 user.info vhusbdchglar300m16[1474]: Unmanaging device 11 [0cad:101a]
Fri Oct 14 13:02:59 2022 kern.info kernel: [ 3143.661481] usb 1-1: new full-speed USB device number 9 using ehci-platform
Fri Oct 14 13:03:00 2022 user.info vhusbdchglar300m16[1474]: Found Full speed device [0cad:101a] "Motorola Solutions, Inc., Motorola APX Series Control Head" at address 11
Fri Oct 14 13:03:00 2022 kern.info kernel: [ 3144.041489] usb 1-1: reset full-speed USB device number 9 using ehci-platform
Fri Oct 14 13:03:00 2022 user.info vhusbdchglar300m16[1474]: Device 11 [0cad:101a] BOUND to connection 1
Fri Oct 14 13:03:00 2022 kern.info kernel: [ 3144.601485] usb 1-1: reset full-speed USB device number 9 using ehci-platform
Fri Oct 14 13:04:57 2022 user.info vhusbdchglar300m16[1474]: Device 11 [0cad:101a] SURPRISE UNBOUND from connection 1
Fri Oct 14 13:04:57 2022 kern.info kernel: [ 3260.937301] usb 1-1: USB disconnect, device number 9
Fri Oct 14 13:04:57 2022 user.info vhusbdchglar300m16[1474]: Unmanaging device 11 [0cad:101a]
Fri Oct 14 13:05:14 2022 kern.info kernel: [ 3278.621472] usb 1-1: new full-speed USB device number 10 using ehci-platform
Fri Oct 14 13:05:14 2022 user.info vhusbdchglar300m16[1474]: Found Full speed device [0cad:101a] "Motorola Solutions, Inc., Motorola APX Series Control Head" at address 11
Fri Oct 14 13:05:15 2022 kern.info kernel: [ 3278.991482] usb 1-1: reset full-speed USB device number 10 using ehci-platform
Fri Oct 14 13:05:15 2022 user.info vhusbdchglar300m16[1474]: Device 11 [0cad:101a] BOUND to connection 1
Fri Oct 14 13:05:15 2022 kern.info kernel: [ 3279.541477] usb 1-1: reset full-speed USB device number 10 using ehci-platform
Fri Oct 14 13:06:30 2022 kern.info kernel: [ 3354.682891] usb 1-1: USB disconnect, device number 10
Fri Oct 14 13:06:30 2022 user.info vhusbdchglar300m16[1474]: Device 11 [0cad:101a] SURPRISE UNBOUND from connection 1
Fri Oct 14 13:06:30 2022 user.info vhusbdchglar300m16[1474]: Unmanaging device 11 [0cad:101a]
Fri Oct 14 13:06:43 2022 kern.info kernel: [ 3367.071479] usb 1-1: new full-speed USB device number 11 using ehci-platform
Fri Oct 14 13:06:43 2022 user.info vhusbdchglar300m16[1474]: Found Full speed device [0cad:101a] "Motorola Solutions, Inc., Motorola APX Series Control Head" at address 11
Fri Oct 14 13:06:43 2022 kern.info kernel: [ 3367.441489] usb 1-1: reset full-speed USB device number 11 using ehci-platform
Fri Oct 14 13:06:43 2022 user.info vhusbdchglar300m16[1474]: Device 11 [0cad:101a] BOUND to connection 1
Fri Oct 14 13:06:44 2022 kern.info kernel: [ 3368.081476] usb 1-1: reset full-speed USB device number 11 using ehci-platform
Fri Oct 14 13:15:23 2022 kern.info kernel: [ 3886.832837] usb 1-1: USB disconnect, device number 11
Fri Oct 14 13:15:23 2022 user.info vhusbdchglar300m16[1474]: Device 11 [0cad:101a] SURPRISE UNBOUND from connection 1
Fri Oct 14 13:15:23 2022 user.info vhusbdchglar300m16[1474]: Unmanaging device 11 [0cad:101a]
Fri Oct 14 13:15:30 2022 kern.info kernel: [ 3894.441440] usb 1-1: new full-speed USB device number 12 using ehci-platform
Fri Oct 14 13:15:30 2022 user.info vhusbdchglar300m16[1474]: Found Full speed device [0cad:1051] "Motorola Solutions, Inc., Motorola APX Series Radio" at address 11
Fri Oct 14 13:15:37 2022 user.info vhusbdchglar300m16[1474]: Unmanaging device 11 [0cad:1051]
Fri Oct 14 13:15:37 2022 kern.info kernel: [ 3901.251947] usb 1-1: USB disconnect, device number 12
Fri Oct 14 13:15:49 2022 kern.info kernel: [ 3913.071438] usb 1-1: new full-speed USB device number 13 using ehci-platform
Fri Oct 14 13:15:49 2022 user.info vhusbdchglar300m16[1474]: Found Full speed device [0cad:1051] "Motorola Solutions, Inc., Motorola APX Series Radio" at address 11
Fri Oct 14 13:15:53 2022 kern.info kernel: [ 3916.901442] usb 1-1: reset full-speed USB device number 13 using ehci-platform
Fri Oct 14 13:15:53 2022 user.info vhusbdchglar300m16[1474]: Device 11 [0cad:1051] BOUND to connection 1
Fri Oct 14 13:15:53 2022 kern.info kernel: [ 3917.481442] usb 1-1: reset full-speed USB device number 13 using ehci-platform
Fri Oct 14 13:15:54 2022 user.info vhusbdchglar300m16[1474]: Device 11 [0cad:1051] UNBOUND from connection 1
Fri Oct 14 13:15:54 2022 kern.warn kernel: [ 3918.529174] usb 1-1: usbfs: process 7488 (vhusbdchglar300) did not claim interface 1 before use
Fri Oct 14 13:16:00 2022 kern.info kernel: [ 3924.631441] usb 1-1: reset full-speed USB device number 13 using ehci-platform
Fri Oct 14 13:16:00 2022 user.info vhusbdchglar300m16[1474]: Device 11 [0cad:1051] BOUND to connection 1
Fri Oct 14 13:16:01 2022 kern.info kernel: [ 3925.211488] usb 1-1: reset full-speed USB device number 13 using ehci-platform
Fri Oct 14 13:17:27 2022 kern.info kernel: [ 4010.891396] usb 1-1: USB disconnect, device number 13
Fri Oct 14 13:17:27 2022 user.info vhusbdchglar300m16[1474]: Device 11 [0cad:1051] SURPRISE UNBOUND from connection 1
Fri Oct 14 13:17:27 2022 user.info vhusbdchglar300m16[1474]: Unmanaging device 11 [0cad:1051]
Fri Oct 14 13:17:32 2022 kern.info kernel: [ 4016.001452] usb 1-1: new full-speed USB device number 14 using ehci-platform
Fri Oct 14 13:17:47 2022 kern.err kernel: [ 4031.331428] usb 1-1: device descriptor read/64, error -145
Fri Oct 14 13:18:02 2022 kern.err kernel: [ 4046.771430] usb 1-1: device descriptor read/64, error -145
Fri Oct 14 13:18:03 2022 kern.info kernel: [ 4047.041556] usb 1-1: new full-speed USB device number 15 using ehci-platform
Fri Oct 14 13:18:18 2022 kern.err kernel: [ 4062.371428] usb 1-1: device descriptor read/64, error -145
Fri Oct 14 13:18:19 2022 user.info vhusbdchglar300m16[1474]: Remote Admin script sent to client at 192.168.137.1
Fri Oct 14 13:18:33 2022 kern.err kernel: [ 4077.811425] usb 1-1: device descriptor read/64, error -145
Fri Oct 14 13:18:34 2022 kern.info kernel: [ 4077.931489] usb usb1-port1: attempt power cycle
Fri Oct 14 13:18:34 2022 kern.info kernel: [ 4078.401435] usb 1-1: new full-speed USB device number 16 using ehci-platform

 

#2

Ok i have an idea.

1. ssh to the cloudhub

2. type /etc/init.d/vhusbd stop

3. vi /root/config.ini

add the line

ClaimPorts=1

4. Save the file

5. reboot

6. When it comes up again, try programming the radio again via virtualhere

7. If it still fails, can you post the log again

#3

Hi Michael, I am attempting to login with Putty but it refuses a blank user name and password as well as my administrator password.

What is it looking for?

Thanks,

Julian

#4

Username: root

No password, just press enter

#5

Yep! Just figured that out by wild guess. I tried the ClaimPort command and after verifying it saved, no joy.

Logs...

Fri Sep 16 14:06:57 2022 kern.notice kernel: [    0.000000] Linux version 5.10.134 (root@ubuntu) (mips-openwrt-linux-musl-gcc (OpenWrt GCC 11.2.0 r19590-042d558536) 11.2.0, GNU ld (GNU Binutils) 2.37) #0 Sun Jul 31 15:12:47 2022
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] printk: bootconsole [early0] enabled
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] CPU0 revision is: 00019374 (MIPS 24Kc)
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] MIPS: machine is GL.iNet GL-AR300M16
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] SoC: Qualcomm Atheros QCA9533 ver 2 rev 0
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] Initrd not found or empty - disabling initrd
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] Primary instruction cache 64kB, VIPT, 4-way, linesize 32 bytes.
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] Primary data cache 32kB, 4-way, VIPT, cache aliases, linesize 32 bytes
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] Zone ranges:
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000]   Normal   [mem 0x0000000000000000-0x0000000007ffffff]
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] Movable zone start for each node
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] Early memory node ranges
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000]   node   0: [mem 0x0000000000000000-0x0000000007ffffff]
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] Initmem setup node 0 [mem 0x0000000000000000-0x0000000007ffffff]
Fri Sep 16 14:06:57 2022 kern.debug kernel: [    0.000000] On node 0 totalpages: 32768
Fri Sep 16 14:06:57 2022 kern.debug kernel: [    0.000000]   Normal zone: 256 pages used for memmap
Fri Sep 16 14:06:57 2022 kern.debug kernel: [    0.000000]   Normal zone: 0 pages reserved
Fri Sep 16 14:06:57 2022 kern.debug kernel: [    0.000000]   Normal zone: 32768 pages, LIFO batch:7
Fri Sep 16 14:06:57 2022 kern.debug kernel: [    0.000000] pcpu-alloc: s0 r0 d32768 u32768 alloc=1*32768
Fri Sep 16 14:06:57 2022 kern.debug kernel: [    0.000000] pcpu-alloc: [0] 0
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 32512
Fri Sep 16 14:06:57 2022 kern.notice kernel: [    0.000000] Kernel command line: console=ttyS0,115200n8 rootfstype=squashfs,jffs2
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] Dentry cache hash table entries: 16384 (order: 4, 65536 bytes, linear)
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] Inode-cache hash table entries: 8192 (order: 3, 32768 bytes, linear)
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] Writing ErrCtl register=00000000
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] Readback ErrCtl register=00000000
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] Memory: 121620K/131072K available (5090K kernel code, 578K rwdata, 1152K rodata, 1236K init, 194K bss, 9452K reserved, 0K cma-reserved)
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] SLUB: HWalign=32, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] NR_IRQS: 51
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] CPU clock: 650.000 MHz
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] clocksource: MIPS: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 5880801374 ns
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000009] sched_clock: 32 bits at 325MHz, resolution 3ns, wraps every 6607641598ns
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.008300] Calibrating delay loop... 432.53 BogoMIPS (lpj=2162688)
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.074928] pid_max: default: 32768 minimum: 301
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.079949] Mount-cache hash table entries: 1024 (order: 0, 4096 bytes, linear)
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.087651] Mountpoint-cache hash table entries: 1024 (order: 0, 4096 bytes, linear)
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.097644] dyndbg: Ignore empty _ddebug table in a CONFIG_DYNAMIC_DEBUG_CORE build
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.108192] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.118602] futex hash table entries: 256 (order: -1, 3072 bytes, linear)
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.125820] pinctrl core: initialized pinctrl subsystem
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.132947] NET: Registered protocol family 16
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.191485] i2c-gpio i2c: using lines 17 (SDA) and 16 (SCL)
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.204369] clocksource: Switched to clocksource MIPS
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.210852] NET: Registered protocol family 2
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.215772] IP idents hash table entries: 2048 (order: 2, 16384 bytes, linear)
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.224053] tcp_listen_portaddr_hash hash table entries: 512 (order: 0, 4096 bytes, linear)
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.232953] TCP established hash table entries: 1024 (order: 0, 4096 bytes, linear)
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.241046] TCP bind hash table entries: 1024 (order: 0, 4096 bytes, linear)
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.248498] TCP: Hash tables configured (established 1024 bind 1024)
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.255363] UDP hash table entries: 256 (order: 0, 4096 bytes, linear)
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.262277] UDP-Lite hash table entries: 256 (order: 0, 4096 bytes, linear)
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.269991] NET: Registered protocol family 1
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.274661] PCI: CLS 0 bytes, default 32
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.284765] workingset: timestamp_bits=30 max_order=15 bucket_order=0
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.295243] squashfs: version 4.0 (2009/01/31) Phillip Lougher
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.301392] jffs2: version 2.2 (NAND) (SUMMARY) (LZMA) (RTIME) (CMODE_PRIORITY) (c) 2001-2006 Red Hat, Inc.
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.315982] pinctrl-single 1804002c.pinmux: 576 pins, size 72
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.323135] Serial: 8250/16550 driver, 1 ports, IRQ sharing disabled
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.330641] printk: console [ttyS0] disabled
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.335289] 18020000.uart: ttyS0 at MMIO 0x18020000 (irq = 9, base_baud = 1562500) is a 16550A
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.344414] printk: console [ttyS0] enabled
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.353463] printk: bootconsole [early0] disabled
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.374121] spi-nor spi0.0: w25q128 (16384 Kbytes)
Fri Sep 16 14:06:57 2022 kern.notice kernel: [    0.379192] 4 fixed-partitions partitions found on MTD device spi0.0
Fri Sep 16 14:06:57 2022 kern.notice kernel: [    0.385774] Creating 4 MTD partitions on "spi0.0":
Fri Sep 16 14:06:57 2022 kern.notice kernel: [    0.390729] 0x000000000000-0x000000040000 : "u-boot"
Fri Sep 16 14:06:57 2022 kern.notice kernel: [    0.399354] 0x000000040000-0x000000050000 : "u-boot-env"
Fri Sep 16 14:06:57 2022 kern.notice kernel: [    0.405915] 0x000000050000-0x000000ff0000 : "firmware"
Fri Sep 16 14:06:57 2022 kern.notice kernel: [    0.413809] 2 uimage-fw partitions found on MTD device firmware
Fri Sep 16 14:06:57 2022 kern.notice kernel: [    0.420008] Creating 2 MTD partitions on "firmware":
Fri Sep 16 14:06:57 2022 kern.notice kernel: [    0.425152] 0x000000000000-0x000000210000 : "kernel"
Fri Sep 16 14:06:57 2022 kern.notice kernel: [    0.431980] 0x000000210000-0x000000fa0000 : "rootfs"
Fri Sep 16 14:06:57 2022 kern.notice kernel: [    0.438099] mtd: device 4 (rootfs) set to be root filesystem
Fri Sep 16 14:06:57 2022 kern.notice kernel: [    0.444944] 1 squashfs-split partitions found on MTD device rootfs
Fri Sep 16 14:06:57 2022 kern.notice kernel: [    0.451359] 0x0000004a0000-0x000000fa0000 : "rootfs_data"
Fri Sep 16 14:06:57 2022 kern.notice kernel: [    0.457928] 0x000000ff0000-0x000001000000 : "art"
Fri Sep 16 14:06:57 2022 kern.err kernel: [    0.845461] ag71xx 19000000.eth: Could not connect to PHY device. Deferring probe.
Fri Sep 16 14:06:57 2022 kern.info kernel: [    1.538083] switch0: Atheros AR8229 rev. 1 switch registered on mdio.0
Fri Sep 16 14:06:57 2022 kern.info kernel: [    1.596391] ag71xx 1a000000.eth: connected to PHY at fixed-0:00 [uid=00000000, driver=Generic PHY]
Fri Sep 16 14:06:57 2022 kern.info kernel: [    1.606364] eth0: Atheros AG71xx at 0xba000000, irq 5, mode: gmii
Fri Sep 16 14:06:57 2022 kern.info kernel: [    1.612897] i2c /dev entries driver
Fri Sep 16 14:06:57 2022 kern.info kernel: [    1.618571] NET: Registered protocol family 10
Fri Sep 16 14:06:57 2022 kern.info kernel: [    1.630485] Segment Routing with IPv6
Fri Sep 16 14:06:57 2022 kern.info kernel: [    1.634451] NET: Registered protocol family 17
Fri Sep 16 14:06:57 2022 kern.info kernel: [    1.639098] 8021q: 802.1Q VLAN Support v1.8
Fri Sep 16 14:06:57 2022 kern.info kernel: [    1.644206] PCI host bridge /ahb/pcie-controller@180c0000 ranges:
Fri Sep 16 14:06:57 2022 kern.info kernel: [    1.650603]  MEM 0x0000000010000000..0x0000000013ffffff
Fri Sep 16 14:06:57 2022 kern.info kernel: [    1.656016]   IO 0x0000000000000000..0x0000000000000000
Fri Sep 16 14:06:57 2022 kern.warn kernel: [    1.661418] ar724x-pci 180c0000.pcie-controller: PCIe link is down
Fri Sep 16 14:06:57 2022 kern.info kernel: [    1.668025] PCI host bridge to bus 0000:00
Fri Sep 16 14:06:57 2022 kern.info kernel: [    1.672274] pci_bus 0000:00: root bus resource [mem 0x10000000-0x13ffffff]
Fri Sep 16 14:06:57 2022 kern.info kernel: [    1.679401] pci_bus 0000:00: root bus resource [io  0x0000]
Fri Sep 16 14:06:57 2022 kern.info kernel: [    1.685169] pci_bus 0000:00: root bus resource [??? 0x00000000 flags 0x0]
Fri Sep 16 14:06:57 2022 kern.info kernel: [    1.692182] pci_bus 0000:00: No busn resource found for root bus, will use [bus 00-ff]
Fri Sep 16 14:06:57 2022 kern.info kernel: [    1.701204] pci_bus 0000:00: busn_res: [bus 00-ff] end is updated to 00
Fri Sep 16 14:06:57 2022 kern.info kernel: [    2.046469] ag71xx 19000000.eth: connected to PHY at mdio.0:1f:04 [uid=004dd042, driver=Generic PHY]
Fri Sep 16 14:06:57 2022 kern.info kernel: [    2.056852] eth1: Atheros AG71xx at 0xb9000000, irq 4, mode: mii
Fri Sep 16 14:06:57 2022 kern.info kernel: [    2.074281] VFS: Mounted root (squashfs filesystem) readonly on device 31:4.
Fri Sep 16 14:06:57 2022 kern.info kernel: [    2.089233] Freeing unused kernel memory: 1236K
Fri Sep 16 14:06:57 2022 kern.warn kernel: [    2.093918] This architecture does not have kernel memory protection.
Fri Sep 16 14:06:57 2022 kern.info kernel: [    2.100603] Run /sbin/init as init process
Fri Sep 16 14:06:57 2022 kern.debug kernel: [    2.104844]   with arguments:
Fri Sep 16 14:06:57 2022 kern.debug kernel: [    2.104849]     /sbin/init
Fri Sep 16 14:06:57 2022 kern.debug kernel: [    2.104853]   with environment:
Fri Sep 16 14:06:57 2022 kern.debug kernel: [    2.104858]     HOME=/
Fri Sep 16 14:06:57 2022 kern.debug kernel: [    2.104862]     TERM=linux
Fri Sep 16 14:06:57 2022 user.info kernel: [    2.884801] init: Console is alive
Fri Sep 16 14:06:57 2022 user.info kernel: [    2.888842] init: - watchdog -
Fri Sep 16 14:06:57 2022 user.info kernel: [    4.163287] kmodloader: loading kernel modules from /etc/modules-boot.d/*
Fri Sep 16 14:06:57 2022 kern.info kernel: [    4.291041] usbcore: registered new interface driver usbfs
Fri Sep 16 14:06:57 2022 kern.info kernel: [    4.296847] usbcore: registered new interface driver hub
Fri Sep 16 14:06:57 2022 kern.info kernel: [    4.302413] usbcore: registered new device driver usb
Fri Sep 16 14:06:57 2022 kern.info kernel: [    4.316673] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
Fri Sep 16 14:06:57 2022 kern.info kernel: [    4.326717] ehci-fsl: Freescale EHCI Host controller driver
Fri Sep 16 14:06:57 2022 kern.info kernel: [    4.334464] ehci-platform: EHCI generic platform driver
Fri Sep 16 14:06:57 2022 kern.info kernel: [    4.340263] ehci-platform 1b000000.usb: EHCI Host Controller
Fri Sep 16 14:06:57 2022 kern.info kernel: [    4.346204] ehci-platform 1b000000.usb: new USB bus registered, assigned bus number 1
Fri Sep 16 14:06:57 2022 kern.info kernel: [    4.354447] ehci-platform 1b000000.usb: irq 3, io mem 0x1b000000
Fri Sep 16 14:06:57 2022 kern.info kernel: [    4.384391] ehci-platform 1b000000.usb: USB 2.0 started, EHCI 1.00
Fri Sep 16 14:06:57 2022 kern.info kernel: [    4.391767] hub 1-0:1.0: USB hub found
Fri Sep 16 14:06:57 2022 kern.info kernel: [    4.396503] hub 1-0:1.0: 1 port detected
Fri Sep 16 14:06:57 2022 user.info kernel: [    4.406693] kmodloader: done loading kernel modules from /etc/modules-boot.d/*
Fri Sep 16 14:06:57 2022 user.info kernel: [    4.424716] init: - preinit -
Fri Sep 16 14:06:57 2022 kern.info kernel: [    4.772842] usb 1-1: new full-speed USB device number 2 using ehci-platform
Fri Sep 16 14:06:57 2022 kern.notice kernel: [    5.348565] random: procd: uninitialized urandom read (4 bytes read)
Fri Sep 16 14:06:57 2022 kern.notice kernel: [    5.673564] random: jshn: uninitialized urandom read (4 bytes read)
Fri Sep 16 14:06:57 2022 kern.notice kernel: [    5.831598] random: jshn: uninitialized urandom read (4 bytes read)
Fri Sep 16 14:06:57 2022 kern.info kernel: [    6.167506] eth0: link up (1000Mbps/Full duplex)
Fri Sep 16 14:06:57 2022 kern.info kernel: [    6.172320] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
Fri Sep 16 14:06:57 2022 kern.info kernel: [    9.398717] usb 1-1: USB disconnect, device number 2
Fri Sep 16 14:06:57 2022 kern.notice kernel: [   10.507445] jffs2: notice: (494) jffs2_build_xattr_subsystem: complete building xattr subsystem, 42 of xdatum (8 unchecked, 34 orphan) and 44 of xref (34 dead, 0 orphan) found.
Fri Sep 16 14:06:57 2022 user.info kernel: [   10.525927] mount_root: switching to jffs2 overlay
Fri Sep 16 14:06:57 2022 kern.warn kernel: [   10.533361] overlayfs: upper fs does not support tmpfile.
Fri Sep 16 14:06:57 2022 user.warn kernel: [   10.547836] urandom-seed: Seeding with /etc/urandom.seed
Fri Sep 16 14:06:57 2022 kern.info kernel: [   10.668482] eth0: link down
Fri Sep 16 14:06:57 2022 user.info kernel: [   10.685283] procd: - early -
Fri Sep 16 14:06:57 2022 user.info kernel: [   10.688668] procd: - watchdog -
Fri Sep 16 14:06:57 2022 user.info kernel: [   11.402897] procd: - watchdog -
Fri Sep 16 14:06:57 2022 user.info kernel: [   11.512693] procd: - ubus -
Fri Sep 16 14:06:57 2022 kern.notice kernel: [   11.733596] random: ubusd: uninitialized urandom read (4 bytes read)
Fri Sep 16 14:06:57 2022 kern.notice kernel: [   11.742713] random: ubusd: uninitialized urandom read (4 bytes read)
Fri Sep 16 14:06:57 2022 kern.notice kernel: [   11.749937] random: ubusd: uninitialized urandom read (4 bytes read)
Fri Sep 16 14:06:57 2022 user.info kernel: [   11.760052] procd: - init -
Fri Sep 16 14:06:57 2022 kern.notice kernel: [   12.830679] random: jshn: uninitialized urandom read (4 bytes read)
Fri Sep 16 14:06:57 2022 kern.notice kernel: [   12.864536] random: ubusd: uninitialized urandom read (4 bytes read)
Fri Sep 16 14:06:57 2022 kern.notice kernel: [   12.894703] random: ubus: uninitialized urandom read (4 bytes read)
Fri Sep 16 14:06:57 2022 user.info kernel: [   12.930554] kmodloader: loading kernel modules from /etc/modules.d/*
Fri Sep 16 14:06:57 2022 kern.info kernel: [   13.504440] Loading modules backported from Linux version v5.15.58-0-g7d8048d4e064
Fri Sep 16 14:06:57 2022 kern.info kernel: [   13.512276] Backport generated by backports.git v5.15.58-1-0-g42a95ce7
Fri Sep 16 14:06:57 2022 kern.info kernel: [   13.583037] xt_time: kernel timezone is -0000
Fri Sep 16 14:06:57 2022 user.info kernel: [   13.610664] urngd: v1.0.2 started.
Fri Sep 16 14:06:57 2022 kern.debug kernel: [   13.794306] ath: EEPROM regdomain: 0x0
Fri Sep 16 14:06:57 2022 kern.debug kernel: [   13.794322] ath: EEPROM indicates default country code should be used
Fri Sep 16 14:06:57 2022 kern.debug kernel: [   13.794327] ath: doing EEPROM country->regdmn map search
Fri Sep 16 14:06:57 2022 kern.debug kernel: [   13.794403] ath: country maps to regdmn code: 0x3a
Fri Sep 16 14:06:57 2022 kern.debug kernel: [   13.794410] ath: Country alpha2 being used: US
Fri Sep 16 14:06:57 2022 kern.debug kernel: [   13.794415] ath: Regpair used: 0x3a
Fri Sep 16 14:06:57 2022 kern.debug kernel: [   13.806890] ieee80211 phy0: Selected rate control algorithm 'minstrel_ht'
Fri Sep 16 14:06:57 2022 kern.info kernel: [   13.809155] ieee80211 phy0: Atheros AR9531 Rev:2 mem=0xb8100000, irq=13
Fri Sep 16 14:06:57 2022 user.info kernel: [   13.944860] kmodloader: done loading kernel modules from /etc/modules.d/*
Fri Sep 16 14:06:57 2022 kern.notice kernel: [   14.445247] random: crng init done
Fri Sep 16 14:06:57 2022 kern.notice kernel: [   14.448785] random: 23 urandom warning(s) missed due to ratelimiting
Fri Sep 16 14:06:58 2022 authpriv.info dropbear[898]: Not backgrounding
Fri Sep 16 14:06:59 2022 daemon.notice wpa_supplicant[950]: Successfully initialized wpa_supplicant
Fri Sep 16 14:07:00 2022 user.notice : Added device handler type: bonding
Fri Sep 16 14:07:00 2022 user.notice : Added device handler type: 8021ad
Fri Sep 16 14:07:00 2022 user.notice : Added device handler type: 8021q
Fri Sep 16 14:07:00 2022 user.notice : Added device handler type: macvlan
Fri Sep 16 14:07:00 2022 user.notice : Added device handler type: veth
Fri Sep 16 14:07:00 2022 user.notice : Added device handler type: bridge
Fri Sep 16 14:07:00 2022 user.notice : Added device handler type: Network device
Fri Sep 16 14:07:00 2022 user.notice : Added device handler type: tunnel
Fri Sep 16 14:07:01 2022 daemon.notice procd: /etc/rc.d/S96led: setting up led LAN
Fri Sep 16 14:07:04 2022 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?
Fri Sep 16 14:07:04 2022 kern.info kernel: [   23.457353] eth0: link up (1000Mbps/Full duplex)
Fri Sep 16 14:07:04 2022 kern.info kernel: [   23.462780] br-lan: port 1(eth0) entered blocking state
Fri Sep 16 14:07:04 2022 kern.info kernel: [   23.468269] br-lan: port 1(eth0) entered disabled state
Fri Sep 16 14:07:04 2022 kern.info kernel: [   23.473975] device eth0 entered promiscuous mode
Fri Sep 16 14:07:04 2022 kern.info kernel: [   23.497157] br-lan: port 1(eth0) entered blocking state
Fri Sep 16 14:07:04 2022 kern.info kernel: [   23.502573] br-lan: port 1(eth0) entered forwarding state
Fri Sep 16 14:07:04 2022 daemon.notice netifd: Interface 'lan' is enabled
Fri Sep 16 14:07:04 2022 daemon.notice netifd: Interface 'lan' is setting up now
Fri Sep 16 14:07:04 2022 daemon.notice netifd: Interface 'lan' is now up
Fri Sep 16 14:07:04 2022 daemon.notice netifd: bridge 'br-lan' link is up
Fri Sep 16 14:07:04 2022 daemon.notice netifd: Interface 'lan' has link connectivity
Fri Sep 16 14:07:04 2022 daemon.notice netifd: Interface 'loopback' is enabled
Fri Sep 16 14:07:04 2022 daemon.notice netifd: Interface 'loopback' is setting up now
Fri Sep 16 14:07:04 2022 daemon.notice netifd: Interface 'loopback' is now up
Fri Sep 16 14:07:04 2022 daemon.notice netifd: Interface 'wan' is enabled
Fri Sep 16 14:07:04 2022 daemon.notice netifd: Interface 'wan6' is enabled
Fri Sep 16 14:07:04 2022 daemon.notice netifd: Network device 'eth0' link is up
Fri Sep 16 14:07:04 2022 daemon.notice netifd: Network device 'lo' link is up
Fri Sep 16 14:07:04 2022 daemon.notice netifd: Interface 'loopback' has link connectivity
Fri Sep 16 14:07:05 2022 kern.info kernel: [   24.547433] IPv6: ADDRCONF(NETDEV_CHANGE): br-lan: link becomes ready
Fri Sep 16 14:07:06 2022 daemon.notice netifd: radio0 (1223): sh: out of range
Fri Sep 16 14:07:07 2022 daemon.info procd: - init complete -
Fri Sep 16 14:07:07 2022 kern.warn kernel: [   26.339976] process '/root/vhusbdchglar300m16' started with executable stack
Fri Sep 16 14:07:08 2022 user.info vhusbdchglar300m16[1482]: >>> Starting VirtualHere USB Server v4.4.2 (Built: Aug 16 2022, 18:44:22)<<<
Fri Sep 16 14:07:08 2022 user.info vhusbdchglar300m16[1482]: Using configuration /root/config.ini
Fri Sep 16 14:07:08 2022 daemon.notice netifd: Wireless device 'radio0' is now up
Fri Sep 16 14:07:08 2022 daemon.notice netifd: Interface 'wwlan' is enabled
Fri Sep 16 14:07:08 2022 user.info vhusbdchglar300m16[1482]: Server licensed to=unlicensed max_devices=1
Fri Sep 16 14:07:08 2022 user.info vhusbdchglar300m16[1482]: Using large URB's
Fri Sep 16 14:07:08 2022 user.info vhusbdchglar300m16[1482]: Listening on all network interfaces at TCP port 7575
Fri Sep 16 14:07:08 2022 user.info vhusbdchglar300m16[1482]: Claiming 1 ports on hub /dev/bus/usb/001/001
Fri Sep 16 14:07:09 2022 daemon.notice wpa_supplicant[950]: wlan0: SME: Trying to authenticate with de:71:96:21:17:90 (SSID='PolkRM' freq=2437 MHz)
Fri Sep 16 14:07:09 2022 kern.info kernel: [   28.466554] wlan0: authenticate with de:71:96:21:17:90
Fri Sep 16 14:07:09 2022 kern.info kernel: [   28.485428] wlan0: send auth to de:71:96:21:17:90 (try 1/3)
Fri Sep 16 14:07:09 2022 daemon.notice wpa_supplicant[950]: wlan0: Trying to associate with de:71:96:21:17:90 (SSID='PolkRM' freq=2437 MHz)
Fri Sep 16 14:07:09 2022 kern.info kernel: [   28.503155] wlan0: authenticated
Fri Sep 16 14:07:09 2022 kern.info kernel: [   28.514688] wlan0: associate with de:71:96:21:17:90 (try 1/3)
Fri Sep 16 14:07:09 2022 kern.info kernel: [   28.710606] wlan0: RX AssocResp from de:71:96:21:17:90 (capab=0x8731 status=0 aid=7)
Fri Sep 16 14:07:09 2022 kern.info kernel: [   28.718913] wlan0: associated
Fri Sep 16 14:07:09 2022 daemon.notice netifd: Network device 'wlan0' link is up
Fri Sep 16 14:07:09 2022 daemon.notice netifd: Interface 'wwlan' has link connectivity
Fri Sep 16 14:07:09 2022 daemon.notice netifd: Interface 'wwlan' is setting up now
Fri Sep 16 14:07:09 2022 daemon.notice wpa_supplicant[950]: wlan0: Associated with de:71:96:21:17:90
Fri Sep 16 14:07:09 2022 daemon.notice wpa_supplicant[950]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
Fri Sep 16 14:07:09 2022 daemon.notice wpa_supplicant[950]: wlan0: Unknown event 37
Fri Sep 16 14:07:09 2022 daemon.notice netifd: wwlan (1547): udhcpc: started, v1.35.0
Fri Sep 16 14:07:09 2022 daemon.notice wpa_supplicant[950]: wlan0: WPA: Key negotiation completed with de:71:96:21:17:90 [PTK=CCMP GTK=CCMP]
Fri Sep 16 14:07:09 2022 daemon.notice wpa_supplicant[950]: wlan0: CTRL-EVENT-CONNECTED - Connection to de:71:96:21:17:90 completed [id=0 id_str=]
Fri Sep 16 14:07:09 2022 daemon.notice wpa_supplicant[950]: wlan0: Unknown event 37
Fri Sep 16 14:07:09 2022 kern.info kernel: [   29.082024] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
Fri Sep 16 14:07:10 2022 daemon.notice netifd: wwlan (1547): udhcpc: broadcasting discover
Fri Sep 16 14:07:10 2022 daemon.notice netifd: wwlan (1547): udhcpc: broadcasting select for 192.168.137.92, server 192.168.137.1
Fri Sep 16 14:07:10 2022 daemon.notice netifd: wwlan (1547): udhcpc: lease of 192.168.137.92 obtained from 192.168.137.1, lease time 604800
Fri Sep 16 14:07:10 2022 daemon.notice netifd: Interface 'wwlan' is now up
Sat Oct 15 01:11:12 2022 user.info vhusbdchglar300m16[1482]: 192.168.137.1 connected as connection 1
Sat Oct 15 01:11:32 2022 kern.info kernel: [   59.184380] usb 1-1: new full-speed USB device number 3 using ehci-platform
Sat Oct 15 01:11:32 2022 user.info vhusbdchglar300m16[1482]: Found Full speed device [0cad:1051] "Motorola Solutions, Inc., Motorola APX Series Radio" at address 11
Sat Oct 15 01:11:32 2022 kern.info kernel: [   59.574384] usb 1-1: reset full-speed USB device number 3 using ehci-platform
Sat Oct 15 01:11:32 2022 user.info vhusbdchglar300m16[1482]: Device 11 [0cad:1051] BOUND to connection 1
Sat Oct 15 01:11:33 2022 kern.info kernel: [   60.154392] usb 1-1: reset full-speed USB device number 3 using ehci-platform
Sat Oct 15 01:16:49 2022 user.info vhusbdchglar300m16[1482]: Device 11 [0cad:1051] SURPRISE UNBOUND from connection 1
Sat Oct 15 01:16:49 2022 kern.info kernel: [  376.626510] usb 1-1: USB disconnect, device number 3
Sat Oct 15 01:16:49 2022 user.info vhusbdchglar300m16[1482]: Unmanaging device 11 [0cad:1051]
Sat Oct 15 01:16:54 2022 kern.info kernel: [  381.779935] usb 1-1: new full-speed USB device number 4 using ehci-platform
Sat Oct 15 01:17:09 2022 kern.err kernel: [  397.059886] usb 1-1: device descriptor read/64, error -145
Sat Oct 15 01:17:22 2022 user.info vhusbdchglar300m16[1482]: Remote Admin script sent to client at 192.168.137.1
Sat Oct 15 01:17:25 2022 kern.err kernel: [  412.499836] usb 1-1: device descriptor read/64, error -145
Sat Oct 15 01:17:25 2022 kern.info kernel: [  412.769836] usb 1-1: new full-speed USB device number 5 using ehci-platform
Sat Oct 15 01:17:40 2022 kern.err kernel: [  428.099794] usb 1-1: device descriptor read/64, error -145
 

#6

Try these two things

Right click on the radio in the virtualhere client and select Custom Event Handler... and paste in line

onReset.$VENDOR_ID$.$PRODUCT_ID$=

Then try to program the radio.

Also you can power cycle the usb port on the gl-ar300m16 by right clicking on the radio if you can see it there then selecting Custom Event Handler... and paste in the line:

power_cycle_port

#7

No joy. I tried each of those handler strings seperately and together. Does the power cycle command need a qualifier of some sort before it in the string such as "onReset.power_cycle_port" I tried this but no go. I noticed that even a simple power cycle of the radio leaves the USB port down. At that point the device/radio is no longer visible. Only a server reboot fixes it. 

Fri Sep 16 14:06:57 2022 kern.notice kernel: [    0.000000] Linux version 5.10.134 (root@ubuntu) (mips-openwrt-linux-musl-gcc (OpenWrt GCC 11.2.0 r19590-042d558536) 11.2.0, GNU ld (GNU Binutils) 2.37) #0 Sun Jul 31 15:12:47 2022
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] printk: bootconsole [early0] enabled
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] CPU0 revision is: 00019374 (MIPS 24Kc)
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] MIPS: machine is GL.iNet GL-AR300M16
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] SoC: Qualcomm Atheros QCA9533 ver 2 rev 0
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] Initrd not found or empty - disabling initrd
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] Primary instruction cache 64kB, VIPT, 4-way, linesize 32 bytes.
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] Primary data cache 32kB, 4-way, VIPT, cache aliases, linesize 32 bytes
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] Zone ranges:
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000]   Normal   [mem 0x0000000000000000-0x0000000007ffffff]
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] Movable zone start for each node
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] Early memory node ranges
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000]   node   0: [mem 0x0000000000000000-0x0000000007ffffff]
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] Initmem setup node 0 [mem 0x0000000000000000-0x0000000007ffffff]
Fri Sep 16 14:06:57 2022 kern.debug kernel: [    0.000000] On node 0 totalpages: 32768
Fri Sep 16 14:06:57 2022 kern.debug kernel: [    0.000000]   Normal zone: 256 pages used for memmap
Fri Sep 16 14:06:57 2022 kern.debug kernel: [    0.000000]   Normal zone: 0 pages reserved
Fri Sep 16 14:06:57 2022 kern.debug kernel: [    0.000000]   Normal zone: 32768 pages, LIFO batch:7
Fri Sep 16 14:06:57 2022 kern.debug kernel: [    0.000000] pcpu-alloc: s0 r0 d32768 u32768 alloc=1*32768
Fri Sep 16 14:06:57 2022 kern.debug kernel: [    0.000000] pcpu-alloc: [0] 0
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 32512
Fri Sep 16 14:06:57 2022 kern.notice kernel: [    0.000000] Kernel command line: console=ttyS0,115200n8 rootfstype=squashfs,jffs2
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] Dentry cache hash table entries: 16384 (order: 4, 65536 bytes, linear)
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] Inode-cache hash table entries: 8192 (order: 3, 32768 bytes, linear)
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] Writing ErrCtl register=00000000
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] Readback ErrCtl register=00000000
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] Memory: 121620K/131072K available (5090K kernel code, 578K rwdata, 1152K rodata, 1236K init, 194K bss, 9452K reserved, 0K cma-reserved)
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] SLUB: HWalign=32, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] NR_IRQS: 51
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] CPU clock: 650.000 MHz
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000000] clocksource: MIPS: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 5880801374 ns
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.000009] sched_clock: 32 bits at 325MHz, resolution 3ns, wraps every 6607641598ns
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.008300] Calibrating delay loop... 432.53 BogoMIPS (lpj=2162688)
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.074928] pid_max: default: 32768 minimum: 301
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.079949] Mount-cache hash table entries: 1024 (order: 0, 4096 bytes, linear)
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.087651] Mountpoint-cache hash table entries: 1024 (order: 0, 4096 bytes, linear)
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.097646] dyndbg: Ignore empty _ddebug table in a CONFIG_DYNAMIC_DEBUG_CORE build
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.108192] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.118602] futex hash table entries: 256 (order: -1, 3072 bytes, linear)
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.125820] pinctrl core: initialized pinctrl subsystem
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.132947] NET: Registered protocol family 16
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.191489] i2c-gpio i2c: using lines 17 (SDA) and 16 (SCL)
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.204359] clocksource: Switched to clocksource MIPS
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.210844] NET: Registered protocol family 2
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.215766] IP idents hash table entries: 2048 (order: 2, 16384 bytes, linear)
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.224041] tcp_listen_portaddr_hash hash table entries: 512 (order: 0, 4096 bytes, linear)
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.232941] TCP established hash table entries: 1024 (order: 0, 4096 bytes, linear)
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.241038] TCP bind hash table entries: 1024 (order: 0, 4096 bytes, linear)
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.248490] TCP: Hash tables configured (established 1024 bind 1024)
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.255356] UDP hash table entries: 256 (order: 0, 4096 bytes, linear)
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.262269] UDP-Lite hash table entries: 256 (order: 0, 4096 bytes, linear)
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.269983] NET: Registered protocol family 1
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.274652] PCI: CLS 0 bytes, default 32
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.284760] workingset: timestamp_bits=30 max_order=15 bucket_order=0
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.295245] squashfs: version 4.0 (2009/01/31) Phillip Lougher
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.301392] jffs2: version 2.2 (NAND) (SUMMARY) (LZMA) (RTIME) (CMODE_PRIORITY) (c) 2001-2006 Red Hat, Inc.
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.315977] pinctrl-single 1804002c.pinmux: 576 pins, size 72
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.323132] Serial: 8250/16550 driver, 1 ports, IRQ sharing disabled
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.330632] printk: console [ttyS0] disabled
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.335281] 18020000.uart: ttyS0 at MMIO 0x18020000 (irq = 9, base_baud = 1562500) is a 16550A
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.344406] printk: console [ttyS0] enabled
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.353455] printk: bootconsole [early0] disabled
Fri Sep 16 14:06:57 2022 kern.info kernel: [    0.374114] spi-nor spi0.0: w25q128 (16384 Kbytes)
Fri Sep 16 14:06:57 2022 kern.notice kernel: [    0.379184] 4 fixed-partitions partitions found on MTD device spi0.0
Fri Sep 16 14:06:57 2022 kern.notice kernel: [    0.385774] Creating 4 MTD partitions on "spi0.0":
Fri Sep 16 14:06:57 2022 kern.notice kernel: [    0.390730] 0x000000000000-0x000000040000 : "u-boot"
Fri Sep 16 14:06:57 2022 kern.notice kernel: [    0.399363] 0x000000040000-0x000000050000 : "u-boot-env"
Fri Sep 16 14:06:57 2022 kern.notice kernel: [    0.405923] 0x000000050000-0x000000ff0000 : "firmware"
Fri Sep 16 14:06:57 2022 kern.notice kernel: [    0.413817] 2 uimage-fw partitions found on MTD device firmware
Fri Sep 16 14:06:57 2022 kern.notice kernel: [    0.420017] Creating 2 MTD partitions on "firmware":
Fri Sep 16 14:06:57 2022 kern.notice kernel: [    0.425162] 0x000000000000-0x000000210000 : "kernel"
Fri Sep 16 14:06:57 2022 kern.notice kernel: [    0.431990] 0x000000210000-0x000000fa0000 : "rootfs"
Fri Sep 16 14:06:57 2022 kern.notice kernel: [    0.438108] mtd: device 4 (rootfs) set to be root filesystem
Fri Sep 16 14:06:57 2022 kern.notice kernel: [    0.444952] 1 squashfs-split partitions found on MTD device rootfs
Fri Sep 16 14:06:57 2022 kern.notice kernel: [    0.451358] 0x0000004a0000-0x000000fa0000 : "rootfs_data"
Fri Sep 16 14:06:57 2022 kern.notice kernel: [    0.457920] 0x000000ff0000-0x000001000000 : "art"
Fri Sep 16 14:06:57 2022 kern.err kernel: [    0.845453] ag71xx 19000000.eth: Could not connect to PHY device. Deferring probe.
Fri Sep 16 14:06:57 2022 kern.info kernel: [    1.538075] switch0: Atheros AR8229 rev. 1 switch registered on mdio.0
Fri Sep 16 14:06:57 2022 kern.info kernel: [    1.596376] ag71xx 1a000000.eth: connected to PHY at fixed-0:00 [uid=00000000, driver=Generic PHY]
Fri Sep 16 14:06:57 2022 kern.info kernel: [    1.606355] eth0: Atheros AG71xx at 0xba000000, irq 5, mode: gmii
Fri Sep 16 14:06:57 2022 kern.info kernel: [    1.612891] i2c /dev entries driver
Fri Sep 16 14:06:57 2022 kern.info kernel: [    1.618565] NET: Registered protocol family 10
Fri Sep 16 14:06:57 2022 kern.info kernel: [    1.630477] Segment Routing with IPv6
Fri Sep 16 14:06:57 2022 kern.info kernel: [    1.634441] NET: Registered protocol family 17
Fri Sep 16 14:06:57 2022 kern.info kernel: [    1.639090] 8021q: 802.1Q VLAN Support v1.8
Fri Sep 16 14:06:57 2022 kern.info kernel: [    1.644198] PCI host bridge /ahb/pcie-controller@180c0000 ranges:
Fri Sep 16 14:06:57 2022 kern.info kernel: [    1.650605]  MEM 0x0000000010000000..0x0000000013ffffff
Fri Sep 16 14:06:57 2022 kern.info kernel: [    1.656016]   IO 0x0000000000000000..0x0000000000000000
Fri Sep 16 14:06:57 2022 kern.warn kernel: [    1.661418] ar724x-pci 180c0000.pcie-controller: PCIe link is down
Fri Sep 16 14:06:57 2022 kern.info kernel: [    1.668025] PCI host bridge to bus 0000:00
Fri Sep 16 14:06:57 2022 kern.info kernel: [    1.672274] pci_bus 0000:00: root bus resource [mem 0x10000000-0x13ffffff]
Fri Sep 16 14:06:57 2022 kern.info kernel: [    1.679401] pci_bus 0000:00: root bus resource [io  0x0000]
Fri Sep 16 14:06:57 2022 kern.info kernel: [    1.685169] pci_bus 0000:00: root bus resource [??? 0x00000000 flags 0x0]
Fri Sep 16 14:06:57 2022 kern.info kernel: [    1.692182] pci_bus 0000:00: No busn resource found for root bus, will use [bus 00-ff]
Fri Sep 16 14:06:57 2022 kern.info kernel: [    1.701204] pci_bus 0000:00: busn_res: [bus 00-ff] end is updated to 00
Fri Sep 16 14:06:57 2022 kern.info kernel: [    2.046460] ag71xx 19000000.eth: connected to PHY at mdio.0:1f:04 [uid=004dd042, driver=Generic PHY]
Fri Sep 16 14:06:57 2022 kern.info kernel: [    2.056844] eth1: Atheros AG71xx at 0xb9000000, irq 4, mode: mii
Fri Sep 16 14:06:57 2022 kern.info kernel: [    2.074268] VFS: Mounted root (squashfs filesystem) readonly on device 31:4.
Fri Sep 16 14:06:57 2022 kern.info kernel: [    2.089219] Freeing unused kernel memory: 1236K
Fri Sep 16 14:06:57 2022 kern.warn kernel: [    2.093902] This architecture does not have kernel memory protection.
Fri Sep 16 14:06:57 2022 kern.info kernel: [    2.100587] Run /sbin/init as init process
Fri Sep 16 14:06:57 2022 kern.debug kernel: [    2.104827]   with arguments:
Fri Sep 16 14:06:57 2022 kern.debug kernel: [    2.104832]     /sbin/init
Fri Sep 16 14:06:57 2022 kern.debug kernel: [    2.104837]   with environment:
Fri Sep 16 14:06:57 2022 kern.debug kernel: [    2.104841]     HOME=/
Fri Sep 16 14:06:57 2022 kern.debug kernel: [    2.104845]     TERM=linux
Fri Sep 16 14:06:57 2022 user.info kernel: [    2.884726] init: Console is alive
Fri Sep 16 14:06:57 2022 user.info kernel: [    2.888769] init: - watchdog -
Fri Sep 16 14:06:57 2022 user.info kernel: [    4.163343] kmodloader: loading kernel modules from /etc/modules-boot.d/*
Fri Sep 16 14:06:57 2022 kern.info kernel: [    4.290566] usbcore: registered new interface driver usbfs
Fri Sep 16 14:06:57 2022 kern.info kernel: [    4.296368] usbcore: registered new interface driver hub
Fri Sep 16 14:06:57 2022 kern.info kernel: [    4.301945] usbcore: registered new device driver usb
Fri Sep 16 14:06:57 2022 kern.info kernel: [    4.316293] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
Fri Sep 16 14:06:57 2022 kern.info kernel: [    4.326300] ehci-fsl: Freescale EHCI Host controller driver
Fri Sep 16 14:06:57 2022 kern.info kernel: [    4.333991] ehci-platform: EHCI generic platform driver
Fri Sep 16 14:06:57 2022 kern.info kernel: [    4.339844] ehci-platform 1b000000.usb: EHCI Host Controller
Fri Sep 16 14:06:57 2022 kern.info kernel: [    4.345789] ehci-platform 1b000000.usb: new USB bus registered, assigned bus number 1
Fri Sep 16 14:06:57 2022 kern.info kernel: [    4.354010] ehci-platform 1b000000.usb: irq 3, io mem 0x1b000000
Fri Sep 16 14:06:57 2022 kern.info kernel: [    4.384383] ehci-platform 1b000000.usb: USB 2.0 started, EHCI 1.00
Fri Sep 16 14:06:57 2022 kern.info kernel: [    4.391724] hub 1-0:1.0: USB hub found
Fri Sep 16 14:06:57 2022 kern.info kernel: [    4.396440] hub 1-0:1.0: 1 port detected
Fri Sep 16 14:06:57 2022 user.info kernel: [    4.404658] kmodloader: done loading kernel modules from /etc/modules-boot.d/*
Fri Sep 16 14:06:57 2022 user.info kernel: [    4.422775] init: - preinit -
Fri Sep 16 14:06:57 2022 kern.info kernel: [    4.770958] usb 1-1: new full-speed USB device number 2 using ehci-platform
Fri Sep 16 14:06:57 2022 kern.notice kernel: [    5.347291] random: procd: uninitialized urandom read (4 bytes read)
Fri Sep 16 14:06:57 2022 kern.notice kernel: [    5.672318] random: jshn: uninitialized urandom read (4 bytes read)
Fri Sep 16 14:06:57 2022 kern.notice kernel: [    5.830736] random: jshn: uninitialized urandom read (4 bytes read)
Fri Sep 16 14:06:57 2022 kern.info kernel: [    6.165983] eth0: link up (1000Mbps/Full duplex)
Fri Sep 16 14:06:57 2022 kern.info kernel: [    6.170798] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
Fri Sep 16 14:06:57 2022 kern.notice kernel: [   10.507259] jffs2: notice: (490) jffs2_build_xattr_subsystem: complete building xattr subsystem, 46 of xdatum (8 unchecked, 38 orphan) and 48 of xref (38 dead, 0 orphan) found.
Fri Sep 16 14:06:57 2022 user.info kernel: [   10.525739] mount_root: switching to jffs2 overlay
Fri Sep 16 14:06:57 2022 kern.warn kernel: [   10.533186] overlayfs: upper fs does not support tmpfile.
Fri Sep 16 14:06:57 2022 user.warn kernel: [   10.547668] urandom-seed: Seeding with /etc/urandom.seed
Fri Sep 16 14:06:57 2022 kern.info kernel: [   10.668521] eth0: link down
Fri Sep 16 14:06:57 2022 user.info kernel: [   10.685345] procd: - early -
Fri Sep 16 14:06:57 2022 user.info kernel: [   10.688723] procd: - watchdog -
Fri Sep 16 14:06:57 2022 user.info kernel: [   11.405324] procd: - watchdog -
Fri Sep 16 14:06:57 2022 user.info kernel: [   11.515060] procd: - ubus -
Fri Sep 16 14:06:57 2022 kern.notice kernel: [   11.735764] random: ubusd: uninitialized urandom read (4 bytes read)
Fri Sep 16 14:06:57 2022 kern.notice kernel: [   11.744877] random: ubusd: uninitialized urandom read (4 bytes read)
Fri Sep 16 14:06:57 2022 kern.notice kernel: [   11.752058] random: ubusd: uninitialized urandom read (4 bytes read)
Fri Sep 16 14:06:57 2022 user.info kernel: [   11.762313] procd: - init -
Fri Sep 16 14:06:57 2022 kern.notice kernel: [   12.830730] random: jshn: uninitialized urandom read (4 bytes read)
Fri Sep 16 14:06:57 2022 kern.notice kernel: [   12.874672] random: ubusd: uninitialized urandom read (4 bytes read)
Fri Sep 16 14:06:57 2022 kern.notice kernel: [   12.904674] random: ubus: uninitialized urandom read (4 bytes read)
Fri Sep 16 14:06:57 2022 user.info kernel: [   12.918008] kmodloader: loading kernel modules from /etc/modules.d/*
Fri Sep 16 14:06:57 2022 kern.info kernel: [   13.490155] Loading modules backported from Linux version v5.15.58-0-g7d8048d4e064
Fri Sep 16 14:06:57 2022 kern.info kernel: [   13.498062] Backport generated by backports.git v5.15.58-1-0-g42a95ce7
Fri Sep 16 14:06:57 2022 kern.info kernel: [   13.585345] xt_time: kernel timezone is -0000
Fri Sep 16 14:06:57 2022 user.info kernel: [   13.611914] urngd: v1.0.2 started.
Fri Sep 16 14:06:57 2022 kern.debug kernel: [   13.801077] ath: EEPROM regdomain: 0x0
Fri Sep 16 14:06:57 2022 kern.debug kernel: [   13.801093] ath: EEPROM indicates default country code should be used
Fri Sep 16 14:06:57 2022 kern.debug kernel: [   13.801098] ath: doing EEPROM country->regdmn map search
Fri Sep 16 14:06:57 2022 kern.debug kernel: [   13.801116] ath: country maps to regdmn code: 0x3a
Fri Sep 16 14:06:57 2022 kern.debug kernel: [   13.801122] ath: Country alpha2 being used: US
Fri Sep 16 14:06:57 2022 kern.debug kernel: [   13.801127] ath: Regpair used: 0x3a
Fri Sep 16 14:06:57 2022 kern.debug kernel: [   13.813597] ieee80211 phy0: Selected rate control algorithm 'minstrel_ht'
Fri Sep 16 14:06:57 2022 kern.info kernel: [   13.815931] ieee80211 phy0: Atheros AR9531 Rev:2 mem=0xb8100000, irq=13
Fri Sep 16 14:06:57 2022 user.info kernel: [   13.934882] kmodloader: done loading kernel modules from /etc/modules.d/*
Fri Sep 16 14:06:57 2022 kern.notice kernel: [   14.423874] random: crng init done
Fri Sep 16 14:06:57 2022 kern.notice kernel: [   14.427483] random: 23 urandom warning(s) missed due to ratelimiting
Fri Sep 16 14:06:58 2022 authpriv.info dropbear[895]: Not backgrounding
Fri Sep 16 14:06:59 2022 daemon.notice wpa_supplicant[947]: Successfully initialized wpa_supplicant
Fri Sep 16 14:07:00 2022 user.notice : Added device handler type: bonding
Fri Sep 16 14:07:00 2022 user.notice : Added device handler type: 8021ad
Fri Sep 16 14:07:00 2022 user.notice : Added device handler type: 8021q
Fri Sep 16 14:07:00 2022 user.notice : Added device handler type: macvlan
Fri Sep 16 14:07:00 2022 user.notice : Added device handler type: veth
Fri Sep 16 14:07:00 2022 user.notice : Added device handler type: bridge
Fri Sep 16 14:07:00 2022 user.notice : Added device handler type: Network device
Fri Sep 16 14:07:00 2022 user.notice : Added device handler type: tunnel
Fri Sep 16 14:07:01 2022 daemon.notice procd: /etc/rc.d/S96led: setting up led LAN
Fri Sep 16 14:07:04 2022 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?
Fri Sep 16 14:07:04 2022 kern.info kernel: [   23.479022] eth0: link up (1000Mbps/Full duplex)
Fri Sep 16 14:07:04 2022 kern.info kernel: [   23.484811] br-lan: port 1(eth0) entered blocking state
Fri Sep 16 14:07:04 2022 kern.info kernel: [   23.490222] br-lan: port 1(eth0) entered disabled state
Fri Sep 16 14:07:04 2022 kern.info kernel: [   23.496000] device eth0 entered promiscuous mode
Fri Sep 16 14:07:04 2022 kern.info kernel: [   23.516949] br-lan: port 1(eth0) entered blocking state
Fri Sep 16 14:07:04 2022 kern.info kernel: [   23.522365] br-lan: port 1(eth0) entered forwarding state
Fri Sep 16 14:07:04 2022 daemon.notice netifd: Interface 'lan' is enabled
Fri Sep 16 14:07:04 2022 daemon.notice netifd: Interface 'lan' is setting up now
Fri Sep 16 14:07:04 2022 daemon.notice netifd: Interface 'lan' is now up
Fri Sep 16 14:07:04 2022 daemon.notice netifd: bridge 'br-lan' link is up
Fri Sep 16 14:07:04 2022 daemon.notice netifd: Interface 'lan' has link connectivity
Fri Sep 16 14:07:04 2022 daemon.notice netifd: Interface 'loopback' is enabled
Fri Sep 16 14:07:04 2022 daemon.notice netifd: Interface 'loopback' is setting up now
Fri Sep 16 14:07:04 2022 daemon.notice netifd: Interface 'loopback' is now up
Fri Sep 16 14:07:04 2022 daemon.notice netifd: Interface 'wan' is enabled
Fri Sep 16 14:07:04 2022 daemon.notice netifd: Interface 'wan6' is enabled
Fri Sep 16 14:07:04 2022 daemon.notice netifd: Network device 'eth0' link is up
Fri Sep 16 14:07:04 2022 daemon.notice netifd: Network device 'lo' link is up
Fri Sep 16 14:07:04 2022 daemon.notice netifd: Interface 'loopback' has link connectivity
Fri Sep 16 14:07:05 2022 kern.info kernel: [   24.509075] IPv6: ADDRCONF(NETDEV_CHANGE): br-lan: link becomes ready
Fri Sep 16 14:07:06 2022 daemon.notice netifd: radio0 (1221): sh: out of range
Fri Sep 16 14:07:07 2022 daemon.info procd: - init complete -
Fri Sep 16 14:07:07 2022 kern.warn kernel: [   26.371517] process '/root/vhusbdchglar300m16' started with executable stack
Fri Sep 16 14:07:08 2022 user.info vhusbdchglar300m16[1479]: >>> Starting VirtualHere USB Server v4.4.2 (Built: Aug 16 2022, 18:44:22)<<<
Fri Sep 16 14:07:08 2022 user.info vhusbdchglar300m16[1479]: Using configuration /root/config.ini
Fri Sep 16 14:07:08 2022 daemon.notice netifd: Wireless device 'radio0' is now up
Fri Sep 16 14:07:08 2022 daemon.notice netifd: Interface 'wwlan' is enabled
Fri Sep 16 14:07:08 2022 user.info vhusbdchglar300m16[1479]: Server licensed to=unlicensed max_devices=1
Fri Sep 16 14:07:08 2022 user.info vhusbdchglar300m16[1479]: Using large URB's
Fri Sep 16 14:07:08 2022 user.info vhusbdchglar300m16[1479]: Listening on all network interfaces at TCP port 7575
Fri Sep 16 14:07:08 2022 user.info vhusbdchglar300m16[1479]: Claiming 1 ports on hub /dev/bus/usb/001/001
Fri Sep 16 14:07:08 2022 user.info vhusbdchglar300m16[1479]: Found Full speed device [0cad:1051] "Motorola Solutions, Inc., Motorola APX Series Radio" at address 11
Fri Sep 16 14:07:09 2022 daemon.notice wpa_supplicant[947]: wlan0: SME: Trying to authenticate with de:71:96:21:17:90 (SSID='PolkRM' freq=2437 MHz)
Fri Sep 16 14:07:09 2022 kern.info kernel: [   28.485910] wlan0: authenticate with de:71:96:21:17:90
Fri Sep 16 14:07:09 2022 kern.info kernel: [   28.504811] wlan0: send auth to de:71:96:21:17:90 (try 1/3)
Fri Sep 16 14:07:09 2022 daemon.notice wpa_supplicant[947]: wlan0: Trying to associate with de:71:96:21:17:90 (SSID='PolkRM' freq=2437 MHz)
Fri Sep 16 14:07:09 2022 kern.info kernel: [   28.521766] wlan0: authenticated
Fri Sep 16 14:07:09 2022 kern.info kernel: [   28.534684] wlan0: associate with de:71:96:21:17:90 (try 1/3)
Fri Sep 16 14:07:09 2022 daemon.notice wpa_supplicant[947]: wlan0: Associated with de:71:96:21:17:90
Fri Sep 16 14:07:09 2022 kern.info kernel: [   28.549863] wlan0: RX AssocResp from de:71:96:21:17:90 (capab=0x8731 status=0 aid=10)
Fri Sep 16 14:07:09 2022 kern.info kernel: [   28.558352] wlan0: associated
Fri Sep 16 14:07:09 2022 daemon.notice netifd: Network device 'wlan0' link is up
Fri Sep 16 14:07:09 2022 daemon.notice netifd: Interface 'wwlan' has link connectivity
Fri Sep 16 14:07:09 2022 daemon.notice netifd: Interface 'wwlan' is setting up now
Fri Sep 16 14:07:09 2022 daemon.notice wpa_supplicant[947]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
Fri Sep 16 14:07:09 2022 daemon.notice wpa_supplicant[947]: wlan0: Unknown event 37
Fri Sep 16 14:07:09 2022 daemon.notice netifd: wwlan (1547): udhcpc: started, v1.35.0
Fri Sep 16 14:07:09 2022 daemon.notice wpa_supplicant[947]: wlan0: WPA: Key negotiation completed with de:71:96:21:17:90 [PTK=CCMP GTK=CCMP]
Fri Sep 16 14:07:09 2022 daemon.notice wpa_supplicant[947]: wlan0: CTRL-EVENT-CONNECTED - Connection to de:71:96:21:17:90 completed [id=0 id_str=]
Fri Sep 16 14:07:09 2022 daemon.notice wpa_supplicant[947]: wlan0: Unknown event 37
Fri Sep 16 14:07:09 2022 kern.info kernel: [   28.923929] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
Fri Sep 16 14:07:10 2022 daemon.notice netifd: wwlan (1547): udhcpc: broadcasting discover
Fri Sep 16 14:07:10 2022 daemon.notice netifd: wwlan (1547): udhcpc: broadcasting select for 192.168.137.239, server 192.168.137.1
Fri Sep 16 14:07:10 2022 daemon.notice netifd: wwlan (1547): udhcpc: lease of 192.168.137.239 obtained from 192.168.137.1, lease time 604800
Fri Sep 16 14:07:10 2022 daemon.notice netifd: Interface 'wwlan' is now up
Fri Sep 16 14:07:18 2022 user.info vhusbdchglar300m16[1479]: 192.168.137.1 connected as connection 1
Fri Sep 16 14:07:28 2022 user.info vhusbdchglar300m16[1479]: Executed "" for onReset.0cad.1051
Fri Sep 16 14:07:28 2022 user.info vhusbdchglar300m16[1479]: Device 11 [0cad:1051] BOUND to connection 1
Fri Sep 16 14:07:29 2022 user.info vhusbdchglar300m16[1479]: Executed "" for onReset.0cad.1051
Fri Sep 16 14:08:49 2022 kern.info kernel: [  128.928273] usb 1-1: USB disconnect, device number 2
Fri Sep 16 14:08:49 2022 user.info vhusbdchglar300m16[1479]: Device 11 [0cad:1051] SURPRISE UNBOUND from connection 1
Fri Sep 16 14:08:49 2022 user.info vhusbdchglar300m16[1479]: Unmanaging device 11 [0cad:1051]
Fri Sep 16 14:09:00 2022 kern.info kernel: [  139.304364] usb 1-1: new full-speed USB device number 3 using ehci-platform
Fri Sep 16 14:09:15 2022 kern.err kernel: [  154.594364] usb 1-1: device descriptor read/64, error -145
Fri Sep 16 14:09:45 2022 kern.info kernel: [  184.374361] usb 1-1: new full-speed USB device number 4 using ehci-platform
Fri Sep 16 14:10:00 2022 kern.err kernel: [  199.634364] usb 1-1: device descriptor read/64, error -145
Fri Sep 16 14:10:15 2022 kern.err kernel: [  215.074361] usb 1-1: device descriptor read/64, error -145
Fri Sep 16 14:10:16 2022 kern.info kernel: [  215.344362] usb 1-1: new full-speed USB device number 5 using ehci-platform
Fri Sep 16 14:10:31 2022 kern.err kernel: [  230.674379] usb 1-1: device descriptor read/64, error -145
Fri Sep 16 14:10:47 2022 kern.err kernel: [  246.114359] usb 1-1: device descriptor read/64, error -145
Fri Sep 16 14:10:47 2022 kern.info kernel: [  246.234404] usb usb1-port1: attempt power cycle
Fri Sep 16 14:10:47 2022 kern.info kernel: [  246.704365] usb 1-1: new full-speed USB device number 6 using ehci-platform
Fri Sep 16 14:10:58 2022 kern.err kernel: [  257.304359] usb 1-1: device not accepting address 6, error -145
Fri Sep 16 14:10:58 2022 kern.info kernel: [  257.454360] usb 1-1: new full-speed USB device number 7 using ehci-platform
Fri Sep 16 14:11:08 2022 kern.err kernel: [  268.024363] usb 1-1: device not accepting address 7, error -145
Fri Sep 16 14:11:08 2022 kern.err kernel: [  268.031986] usb usb1-port1: unable to enumerate USB device
Fri Sep 16 14:16:54 2022 user.info vhusbdchglar300m16[1479]: Remote Admin script sent to client at 192.168.137.1
 

#8

What looks like happening is that after you program the radio, the radio reboots itself inside its firmware. This causes it to drop off the USB bus (but still be physically plugged in).

What would normally happen is it would come back a few seconds later and be visible again - however in your case, after the firmware reboots the device fails to enumerate and and respond to fundamental USB transmissions like "this is your address on the USB bus" (this is the meaning of the not accepting address error)

The last thing to try is to put a separately powered USB hub between the cloudhub and the radio. My other guess is perhaps when the radio reboots its firmware and starts again it may need more power from the USB port than the router can provide. Just for a test, if you can provide a separately powered USB hub in between perhaps that would provide enough power for it to reboot successfully and finish writing its firmware.

At the moment, when it does come back after you reboot the router, is the radio actually programmed successfully or does it fail to reprogram entirely?

#9

The radio has its own power supply/battery so it doesn't get any power from the iNet router, it's data only.

This happens with just a simple power cycle of the radio as well.

What is causing or why does the port end up permanently disabled?

What is the criteria to reenable the port after this happens? Is a reboot the only way?

Is there a command that can reboot the server or port based on the error 145?

Or a command to restart the port after a failure to enumerate?

Just thinking out loud. 

I will also capture a log from a successful reboot and enumeration of a mobile radio to see if you can gleen anything from that.

Thanks much,

Julian

#10

The error: device descriptor read/64, error -145 is not related to virtualhere. Its an error from Linux before virtualhere even sees the device. The device is not responding at all to the "SET_ADDRESS" request which is a basic fundamental usb transmission (as described above).

It might be taking a few seconds to reboot or something and linux is expecting the radio to respond within a second or two. So it times out after a minute and linux tries to power cycle the usb port as it thinks the usb device is invalid (which technically it is while its not responding to anything)

Does the radio successfully reprogram anyway, when it all reconnects again after rebooting the router?

Also if you want i can take a quick look via teamviewer while you are there? Let me know by email mail [at] virtualhere.com (mail[at]virtualhere[dot]com) if you want to do this