OpenWRT x86 23.05, IO Freezes randomly and then recovers after plugging a USB device

vincejv · November 3, 2023, 10:37am

Hi I'm having a weird issue after upgrading to OpenWRT x86 23.05, the IO (SSD) is freezing randomly and what's really weird is after inserting any USB device in the computer, may it be a keyboard or flash drive, the system magically responds again, also only the IO is frozen, I still have routing, internet and pppoe enabled and connected, luci is still also responsive except those function requiring IO like viewing the system logs (as it requires reading from IO in tmpfs), it's just that the file system is inaccessible, even logread won't load the logs, SSH is also inaccessible and existing SSH connections are frozen.

Kernel logs are still accessible and this is the part where it recovers from a frozen IO. I couldn't retrieve the system logs from logread as after the system recovers from a frozen state, the system logs are wiped out, but I will try to change to persistent logging.

My suspect is there is a bug in the kernel interrupts, I don't have irqbalance installed, just packet steering enabled, also using the stock x86 kernel.

[40146.294809] br-49c181f3cd08: port 24(veth204b9d7) entered disabled state
[40180.307091] usb 1-1.4: new high-speed USB device number 4 using ehci-pci
[40180.520002] usb-storage 1-1.4:1.0: USB Mass Storage device detected
[40180.526654] scsi host6: usb-storage 1-1.4:1.0
[40181.573675] scsi 6:0:0:0: Direct-Access     Generic- SD/MMC           1.00 PQ: 0 ANSI: 0 CCS
[40181.588656] scsi 6:0:0:1: Direct-Access     Generic- MS/MS-Pro        1.00 PQ: 0 ANSI: 0 CCS
[40183.447778] usb 1-1.4: USB disconnect, device number 4
[40183.487157] sd 6:0:0:0: [sdc] Test Unit Ready failed: Result: hostbyte=0x01 driverbyte=DRIVER_OK
[40183.496041] sd 6:0:0:0: [sdc] Read Capacity(10) failed: Result: hostbyte=0x01 driverbyte=DRIVER_OK
[40183.496084] sd 6:0:0:1: [sdd] Test Unit Ready failed: Result: hostbyte=0x01 driverbyte=DRIVER_OK
[40183.505054] sd 6:0:0:0: [sdc] Sense not available.
[40183.514036] sd 6:0:0:1: [sdd] Read Capacity(10) failed: Result: hostbyte=0x01 driverbyte=DRIVER_OK
[40183.518723] sd 6:0:0:0: [sdc] 0 512-byte logical blocks: (0 B/0 B)
[40183.518725] sd 6:0:0:0: [sdc] 0-byte physical blocks
[40183.527714] sd 6:0:0:1: [sdd] Sense not available.
[40183.533925] sd 6:0:0:0: [sdc] Write Protect is off
[40183.538924] sd 6:0:0:1: [sdd] 0 512-byte logical blocks: (0 B/0 B)
[40183.543739] sd 6:0:0:0: [sdc] Mode Sense: 00 00 00 00
[40183.548560] sd 6:0:0:1: [sdd] 0-byte physical blocks
[40183.548584] sd 6:0:0:1: [sdd] Test WP failed, assume Write Enabled
[40183.554776] sd 6:0:0:0: [sdc] Asking for cache data failed
[40183.559892] sd 6:0:0:1: [sdd] Asking for cache data failed
[40183.564848] sd 6:0:0:0: [sdc] Assuming drive cache: write through
[40183.571058] sd 6:0:0:1: [sdd] Assuming drive cache: write through
[40183.576689] sd 6:0:0:0: [sdc] Read Capacity(10) failed: Result: hostbyte=0x07 driverbyte=DRIVER_OK
[40183.582242] sd 6:0:0:1: [sdd] Test Unit Ready failed: Result: hostbyte=0x01 driverbyte=DRIVER_OK
[40183.586326] sd 6:0:0:1: [sdd] Test Unit Ready failed: Result: hostbyte=0x01 driverbyte=DRIVER_OK
[40183.588203] sd 6:0:0:0: [sdc] Sense not available.
[40183.588216] sd 6:0:0:0: [sdc] Attached SCSI removable disk
[40183.594324] sd 6:0:0:1: [sdd] Attached SCSI removable disk
[40555.176936] br-49c181f3cd08: port 24(vetha9037c9) entered blo

vincejv · November 3, 2023, 10:38am

I've also checked the SSD drive SMART Statistics and all passed.
CPU: Intel i7 2600k
System Unit: Dell Optiplex 790, Intel Q65 chipset

=== START OF INFORMATION SECTION ===
Device Model:     BR 128GB
Serial Number:    YS20230405615480
LU WWN Device Id: 0 000000 000000000
Firmware Version: HPS2818E
User Capacity:    128,035,676,160 bytes [128 GB]
Sector Size:      512 bytes logical/physical
Rotation Rate:    Solid State Device
Form Factor:      2.5 inches
TRIM Command:     Available
Device is:        Not in smartctl database 7.3/5319
ATA Version is:   ACS-2 T13/2015-D revision 3
SATA Version is:  SATA 3.2, 6.0 Gb/s (current: 6.0 Gb/s)
Local Time is:    Fri Nov  3 22:10:59 2023 PST
SMART support is: Available - device has SMART capability.
SMART support is: Enabled

=== START OF READ SMART DATA SECTION ===
SMART overall-health self-assessment test result: PASSED

General SMART Values:
Offline data collection status:  (0x00)	Offline data collection activity
					was never started.
					Auto Offline Data Collection: Disabled.
Total time to complete Offline 
data collection: 		(    0) seconds.
Offline data collection
capabilities: 			 (0x00) 	Offline data collection not supported.
SMART capabilities:            (0x0000)	Automatic saving of SMART data		is not implemented.
Error logging capability:        (0x00)	Error logging supported.
					General Purpose Logging supported.

SMART Attributes Data Structure revision number: 1
Vendor Specific SMART Attributes with Thresholds:
ID# ATTRIBUTE_NAME          FLAG     VALUE WORST THRESH TYPE      UPDATED  WHEN_FAILED RAW_VALUE
  1 Raw_Read_Error_Rate     0x0032   100   100   050    Old_age   Always       -       0
  5 Reallocated_Sector_Ct   0x0032   100   100   050    Old_age   Always       -       0
  9 Power_On_Hours          0x0032   100   100   050    Old_age   Always       -       819
 12 Power_Cycle_Count       0x0032   100   100   050    Old_age   Always       -       55
160 Unknown_Attribute       0x0032   100   100   050    Old_age   Always       -       0
161 Unknown_Attribute       0x0032   100   100   050    Old_age   Always       -       100
163 Unknown_Attribute       0x0032   100   100   050    Old_age   Always       -       0
164 Unknown_Attribute       0x0032   100   100   050    Old_age   Always       -       151
165 Unknown_Attribute       0x0032   100   100   050    Old_age   Always       -       142
166 Unknown_Attribute       0x0032   100   100   050    Old_age   Always       -       3
167 Unknown_Attribute       0x0032   100   100   050    Old_age   Always       -       69
168 Unknown_Attribute       0x0032   100   100   050    Old_age   Always       -       0
169 Unknown_Attribute       0x0032   100   100   050    Old_age   Always       -       100
175 Program_Fail_Count_Chip 0x0032   100   100   050    Old_age   Always       -       83886080
176 Erase_Fail_Count_Chip   0x0032   100   100   050    Old_age   Always       -       628622
177 Wear_Leveling_Count     0x0032   100   100   050    Old_age   Always       -       3942414
178 Used_Rsvd_Blk_Cnt_Chip  0x0032   100   100   050    Old_age   Always       -       0
181 Program_Fail_Cnt_Total  0x0032   100   100   050    Old_age   Always       -       0
182 Erase_Fail_Count_Total  0x0032   100   100   050    Old_age   Always       -       0
192 Power-Off_Retract_Count 0x0032   100   100   050    Old_age   Always       -       24
194 Temperature_Celsius     0x0032   100   100   050    Old_age   Always       -       40
195 Hardware_ECC_Recovered  0x0032   100   100   050    Old_age   Always       -       0
196 Reallocated_Event_Count 0x0032   100   100   050    Old_age   Always       -       0
197 Current_Pending_Sector  0x0032   100   100   050    Old_age   Always       -       0
198 Offline_Uncorrectable   0x0032   100   100   050    Old_age   Always       -       0
199 UDMA_CRC_Error_Count    0x0032   100   100   050    Old_age   Always       -       0
232 Available_Reservd_Space 0x0032   100   100   050    Old_age   Always       -       100
241 Total_LBAs_Written      0x0032   100   100   050    Old_age   Always       -       26416
242 Total_LBAs_Read         0x0032   100   100   050    Old_age   Always       -       21016

vincejv · November 4, 2023, 11:47am

Encountered a random freeze again today here are the system logs stored in ssd, same situation, i was able to unfreeze it by plugging a usb device, frozen in between Sat Nov 4 18:25:26 2023 - Sat Nov 4 19:42:15 2023

Sat Nov  4 18:25:26 2023 daemon.info ipsec: 15[CFG] joining forecast multicast groups: 224.0.0.1,224.0.0.22,224.0.0.251,224.0.0.252,239.255.255.250
Sat Nov  4 18:25:26 2023 daemon.err dockerd[6215]: time="2023-11-04T10:25:26.453200781Z" level=error msg="failed to enable controllers ([cpuset cpu io memory hugetlb pids rdma])" error="failed to write subtree controllers [cpuset cpu io memory hugetlb pids rdma] to \"/sys/fs/cgroup/docker/cgroup.subtree_control\": write /sys/fs/cgroup/docker/cgroup.subtree_control: no such file or directory"
Sat Nov  4 18:25:26 2023 daemon.err dockerd[6215]: time="2023-11-04T10:25:26.498516755Z" level=warning msg="cleaning up after shim disconnected" id=218f8bacbeb9358d99fdfb826aaa6fabf7a18b11578817aa7d91a2feeae69a1e namespace=moby
Sat Nov  4 18:25:26 2023 daemon.info avahi-daemon[4338]: Interface veth543003f.IPv6 no longer relevant for mDNS.
Sat Nov  4 18:25:26 2023 daemon.info avahi-daemon[4338]: Leaving mDNS multicast group on interface veth543003f.IPv6 with address fe80::5ca6:5ff:fe99:41c.
Sat Nov  4 18:25:26 2023 daemon.info ipsec: 10[KNL] interface veth543003f deactivated
Sat Nov  4 18:25:26 2023 daemon.notice ttyd[7753]: [2023/11/04 18:25:26:8492] N: rops_handle_POLLIN_netlink: DELADDR
Sat Nov  4 18:25:26 2023 daemon.info ipsec: 12[KNL] fe80::5ca6:5ff:fe99:41c disappeared from veth543003f
Sat Nov  4 18:25:26 2023 daemon.info ipsec: 10[KNL] interface vethc66e8b8 deleted
Sat Nov  4 19:42:15 2023 kern.info kernel: [39710.883276] usb 1-1.3: new high-speed USB device number 3 using ehci-pci
Sat Nov  4 19:42:15 2023 daemon.info ipsec: 13[KNL] interface veth543003f deleted
Sat Nov  4 19:42:15 2023 daemon.notice netifd: bridge 'docker0' link is down
Sat Nov  4 19:42:15 2023 daemon.notice netifd: Interface 'docker' has link connectivity loss
Sat Nov  4 19:42:15 2023 daemon.info avahi-daemon[4338]: Withdrawing address record for fe80::5ca6:5ff:fe99:41c on veth543003f.
Sat Nov  4 19:42:15 2023 daemon.info ipsec: 15[NET] using forecast interface br-lan
Sat Nov  4 19:42:15 2023 daemon.info ipsec: 15[CFG] joining forecast multicast groups: 224.0.0.1,224.0.0.22,224.0.0.251,224.0.0.252,239.255.255.250
Sat Nov  4 19:42:15 2023 daemon.info avahi-daemon[4338]: Joining mDNS multicast group on interface vethdb8539e.IPv6 with address fe80::8b8:c8ff:fe99:314d.
Sat Nov  4 19:42:15 2023 daemon.info ipsec: 11[KNL] fe80::8b8:c8ff:fe99:314d appeared on vethdb8539e
Sat Nov  4 19:42:15 2023 daemon.info avahi-daemon[4338]: New relevant interface vethdb8539e.IPv6 for mDNS.
Sat Nov  4 19:42:15 2023 daemon.info avahi-daemon[4338]: Registering new address record for fe80::8b8:c8ff:fe99:314d on vethdb8539e.*.
Sat Nov  4 19:42:15 2023 daemon.info ipsec: 12[NET] using forecast interface br-lan
Sat Nov  4 19:42:15 2023 daemon.info ipsec: 12[CFG] joining forecast multicast groups: 224.0.0.1,224.0.0.22,224.0.0.251,224.0.0.252,239.255.255.250
Sat Nov  4 19:42:15 2023 daemon.info dnsmasq-dhcp[1]: DHCPREQUEST(br-lan) 172.16.0.42 0a:97:77:02:ce:64
Sat Nov  4 19:42:15 2023 daemon.err uhttpd[4082]: [info] luci: accepted login on / for root from 127.0.0.1
Sat Nov  4 19:42:15 2023 authpriv.notice sudo:  vincejv : TTY=pts/0 ; PWD=/home/vincejv ; USER=root ; COMMAND=/sbin/logread
Sat Nov  4 19:42:15 2023 daemon.info dnsmasq-dhcp[1]: DHCPACK(br-lan) 172.16.0.42 0a:97:77:02:ce:64 OPPO-A52
Sat Nov  4 19:42:15 2023 daemon.info dnsmasq-dhcp[1]: DHCPREQUEST(br-lan) 172.16.0.42 0a:97:77:02:ce:64
Sat Nov  4 19:42:15 2023 daemon.info dnsmasq-dhcp[1]: DHCPACK(br-lan) 172.16.0.42 0a:97:77:02:ce:64 OPPO-A52
Sat Nov  4 19:42:15 2023 daemon.info dnsmasq-dhcp[1]: DHCPREQUEST(br-lan) 172.16.0.42 0a:97:77:02:ce:64
Sat Nov  4 19:42:15 2023 daemon.info dnsmasq-dhcp[1]: DHCPACK(br-lan) 172.16.0.42 0a:97:77:02:ce:64 OPPO-A52

Pico · November 4, 2023, 12:10pm

I would first try an active-powered USB hub, to check, whether it is not an USB power issue.

vincejv · November 4, 2023, 1:46pm

But when downgrading to 22.03.5 no issue

frollic · November 4, 2023, 1:53pm

I've had issues with 23.05 on x86 too, but for me, it simply freezes during boot. Rolled back, just as you did.

DjangoR · November 4, 2023, 6:42pm

so much weird problems for me too in 23.05.0... squid crash issues, wifi performance issues; staying on 22.03 for now

azmras · November 28, 2023, 5:34am

The last thing I got on the log before reboot was this

Tue Nov 28 10:30:21 2023 kern.alert kernel: [ 632.608660] CPU 0 Unable to handle kernel paging request at virtual address 00000000, epc == 8016cc5c, ra == 8016f51c

on searching I found the following link, will look into it further ...

github.com/openwrt/openwrt

FS#3538 - ramips-mt7621: CPU 3 Unable to handle kernel paging request at virtual address

opened 10:52PM - 26 Dec 20 UTC

closed 05:36AM - 23 May 22 UTC

openwrt-bot

kernel release/19.07 flyspray

*dfberger:* Model: UBNT-ERX Architecture: MediaTek MT7621 ver:1 eco:3 Firmwar…e Version: OpenWrt 19.07.5 r11257-5090152ae3 / LuCI openwrt-19.07 branch git-20.341.57626-51f55b5 Kernel Version: 4.14.209 <code> # cat /sys/kernel/debug/crashlog Time: 1609020971.160675 Modules: pppoe@8eb00000+2400 ppp_async@8ea24000+1b90 pppox@8e99d000+4b0 ppp_generic@8eb18000+5970 nf_nat_pptp@8f060000+700 nf_conntrack_pptp@8f0d7000+ef0 nf_conntrack_ipv6@8eae8000+1590 iptable_nat@8e91e000+2c0 ipt_REJECT@8e83f000+3c0 ipt_MASQUERADE@8e80c000+2a0 xt_time@8f1b2000+6e0 xt_tcpudp@8f1b0000+700 xt_tcpmss@8f1ba000+420 xt_statistic@8ea1e000+340 xt_state@8e8c6000+2c0 xt_recent@8eb10000+1bf0 xt_nat@8e8c4000+600 xt_multiport@8e8ff000+500 xt_mark@8e8fd000+2a0 xt_mac@8e8d2000+260 xt_limit@8e8db000+4a0 xt_length@8e8d9000+2c0 xt_hl@8e8ce000+320 xt_helper@8eb38000+360 xt_ecn@8eb3a000+540 xt_dscp@8eb3e000+3e0 xt_conntrack@8e8f7000+900 xt_connmark@8e836000+4e0 xt_connlimit@8e8c2000+1510 xt_connbytes@8eafa000+640 xt_comment@8e8e2000+1e0 xt_TCPMSS@8e8e1000+ae0 xt_REDIRECT@8e8e5000+2c0 xt_LOG@8e8ea000+300 xt_HL@8ea57000+540 xt_FLOWOFFLOAD@8e8e9000+c10 xt_DSCP@8e8ec000+5e0 xt_CT@8e8ee000+a60 xt_CLASSIFY@8e8f2000+240 wireguard@8eb20000+166c0 ts_fsm@8e837000+ac0 ts_bm@8eaf6000+580 slhc@8e8c8000+1400 nf_reject_ipv4@8e907000+840 nf_nat_tftp@8f1e5000+220 nf_nat_snmp_basic@8e806000+18d0 nf_nat_sip@8e8ae000+1ee0 nf_nat_redirect@8f1de000+580 nf_nat_proto_gre@8e835000+370 nf_nat_masquerade_ipv4@8e8a0000+650 nf_nat_irc@8f1da000+400 nf_conntrack_ipv4@8e8c0000+1420 nf_nat_ipv4@8ea54000+f30 nf_nat_h323@8ea6a000+1520 nf_nat_amanda@8ea16000+300 nf_nat@8e8a8000+37b0 nf_log_ipv4@8f1e1000+d60 nf_flow_table_hw@8ea9f000+8f0 nf_flow_table@8eaac000+3370 nf_defrag_ipv6@8f1e6000+12e0 nf_defrag_ipv4@8f1bc000+440 nf_conntrack_tftp@8e9fa000+ae0 nf_conntrack_snmp@8ea47000+2f0 nf_conntrack_sip@8e890000+48c0 nf_conntrack_rtcache@8f1ff000+aa0 nf_conntrack_proto_gre@8e803000+a60 nf_conntrack_netlink@8e838000+5a70 nf_conntrack_irc@8e935000+b60 nf_conntrack_h323@8e860000+8a20 nf_conntrack_broadcast@8f1c7000+360 ts_kmp@8eadf000+520 nf_conntrack_amanda@8eaab000+6c0 iptable_raw@8ea66000+260 iptable_mangle@8ea17000+380 iptable_filter@8ea50000+280 ipt_ECN@8f1c4000+580 ip_tables@8e914000+2b30 crc_ccitt@8e80d000+3e0 br_netfilter@8f1f4000+30f0 sch_cake@8ea90000+74d0 act_connmark@8eae7000+830 nf_conntrack@8e840000+10770 sch_tbf@8e826000+1700 sch_ingress@8f1c6000+4c0 sch_htb@8e820000+36d0 sch_hfsc@8e808000+3a00 em_u32@8ea8e000+220 cls_u32@8e800000+22d0 cls_tcindex@8eafc000+1500 cls_route@8eaf4000+1470 cls_matchall@8f1b8000+9e0 cls_fw@8ea51000+f20 cls_flow@8e91a000+1680 cls_basic@8ea4e000+c40 act_skbedit@8ea45000+9f0 act_mirred@8ea46000+f50 xt_set@8eaea000+1b20 ip_set_list_set@8ead6000+1c60 ip_set_hash_netportnet@8eae0000+6c60 ip_set_hash_netport@8ead8000+61e0 ip_set_hash_netnet@8eac8000+6780 ip_set_hash_netiface@8eac0000+62c0 ip_set_hash_net@8eab8000+5c00 ip_set_hash_mac@8eaa8000+2920 ip_set_hash_ipportnet@8eaa0000+6740 ip_set_hash_ipportip@8ea98000+54a0 ip_set_hash_ipport@8ea88000+5140 ip_set_hash_ipmark@8ea80000+4e60 ip_set_hash_ip@8ea78000+4d80 ip_set_bitmap_port@8ea70000+1800 ip_set_bitmap_ipmac@8ea6c000+1ba0 ip_set_bitmap_ip@8ea68000+1b00 ip_set@8ea60000+5690 nfnetlink@8ea52000+1110 nf_log_ipv6@8f1fa000+1020 nf_log_common@8f44b000+aa0 ip6table_mangle@8f06e000+4a0 ip6table_filter@8e99b000+280 ip6_tables@8f1ec000+2a20 ip6t_REJECT@8f7d7000+400 x_tables@8f1e8000+3290 nf_reject_ipv6@8ea22000+9e0 ifb@8f0d2000+ce0ip6_udp_tunnel@8f077000+640 udp_tunnel@8f44e000+980 sit@8f1b4000+37a0 tunnel4@8f1a5000+820 ip_tunnel@8e910000+2c20 usb_storage@8f0e0000+a000 leds_gpio@8f7ce000+b60 sd_mod@8f038000+7430 scsi_mod@8f040000+15770 gpio_button_hotplug@8f7d8000+1ac0 f2fs@8f080000+41fd0 ext4@8f100000+5ebc0 mbcache@8f7d6000+e10 jbd2@8f020000+d4f0 usbcore@8f000000+1fe90 nls_base@8f454000+1430 usb_common@8f7b7000+8c0 crc32c_generic@8f7b4000+560 crc32_generic@8f7b1000+560 <5>[ 1.790896] 0x0000000e0000-0x000000140000 : "factory" <5>[ 1.801981] 0x000000140000-0x000000440000 : "kernel1" <5>[ 1.813075] 0x000000440000-0x000000740000 : "kernel2" <5>[ 1.824242] 0x000000740000-0x00000ff00000 : "ubi" <4>[ 1.836547] [mtk_nand] probe successfully! <4>[ 1.845433] Signature matched and data read! <4>[ 1.853936] load_fact_bbt success 2047 <6>[ 1.862079] libphy: Fixed MDIO Bus: probed <6>[ 1.942611] libphy: mdio: probed <6>[ 3.348616] mtk_soc_eth 1e100000.ethernet: loaded mt7530 driver <6>[ 3.361135] mtk_soc_eth 1e100000.ethernet eth0: mediatek frame engine at 0xbe100000, irq 20 <6>[ 3.380543] NET: Registered protocol family 10 <6>[ 3.390986] Segment Routing with IPv6 <6>[ 3.398358] NET: Registered protocol family 17 <6>[ 3.407323] bridge: filtering via arp/ip/ip6tables is no longer available by default. Update your scripts to load br_netfilter if you need this. <6>[ 3.433121] 8021q: 802.1Q VLAN Support v1.8 <5>[ 3.444288] UBI: auto-attach mtd5 <5>[ 3.450971] ubi0: attaching mtd5 <6>[ 4.898762] mtk_soc_eth 1e100000.ethernet eth0: port 0 link up <6>[ 5.054752] mtk_soc_eth 1e100000.ethernet eth0: port 1 link up <5>[ 5.749269] ubi0: scanning is finished <5>[ 5.774006] ubi0: attached mtd5 (name "ubi", size 247 MiB) <5>[ 5.784953] ubi0: PEB size: 131072 bytes (128 KiB), LEB size: 126976 bytes <5>[ 5.798632] ubi0: min./max. I/O unit sizes: 2048/2048, sub-page size 2048 <5>[ 5.812143] ubi0: VID header offset: 2048 (aligned 2048), data offset: 4096 <5>[ 5.825995] ubi0: good PEBs: 1982, bad PEBs: 0, corrupted PEBs: 0 <5>[ 5.838118] ubi0: user volume: 2, internal volumes: 1, max. volumes count: 128 <5>[ 5.852495] ubi0: max/mean erase counter: 2/0, WL threshold: 4096, image sequence number: 1550099540 <5>[ 5.870672] ubi0: available PEBs: 0, total reserved PEBs: 1982, PEBs reserved for bad PEB handling: 40 <5>[ 5.889214] ubi0: background thread "ubi_bgt0d" started, PID 366 <6>[ 5.891153] block ubiblock0_0: created from ubi0:0(rootfs) <5>[ 5.912133] ubiblock: device ubiblock0_0 (rootfs) set to be root filesystem <6>[ 5.925999] hctosys: unable to open rtc device (rtc0) <6>[ 5.943697] VFS: Mounted root (squashfs filesystem) readonly on device 254:0. <6>[ 5.962156] Freeing unused kernel memory: 1252K <4>[ 5.971197] This architecture does not have kernel memory protection. <14>[ 6.464290] init: Console is alive <14>[ 6.471334] init: - watchdog - <14>[ 7.326596] kmodloader: loading kernel modules from /etc/modules-boot.d/* <6>[ 7.437188] usbcore: registered new interface driver usbfs <6>[ 7.448229] usbcore: registered new interface driver hub <6>[ 7.458977] usbcore: registered new device driver usb <5>[ 7.507708] SCSI subsystem initialized <6>[ 7.520990] usbcore: registered new interface driver usb-storage <14>[ 7.533334] kmodloader: done loading kernel modules from /etc/modules-boot.d/* <14>[ 7.550506] init: - preinit - <6>[ 8.519957] mtk_soc_eth 1e100000.ethernet: PPE started <14>[ 11.735899] mount_root: loading kmods from internal overlay <14>[ 11.778945] kmodloader: loading kernel modules from //etc/modules-boot.d/* <14>[ 11.796110] kmodloader: done loading kernel modules from //etc/modules-boot.d/* <5>[ 12.156598] UBIFS (ubi0:1): background thread "ubifs_bgt0_1" started, PID 470 <5>[ 12.216428] random: procd: uninitialized urandom read (4 bytes read) <5>[ 12.230605] UBIFS (ubi0:1): recovery needed <5>[ 12.424552] UBIFS (ubi0:1): recovery completed <5>[ 12.433524] UBIFS (ubi0:1): UBIFS: mounted UBI device 0, volume 1, name "rootfs_data" <5>[ 12.449109] UBIFS (ubi0:1): LEB size: 126976 bytes (124 KiB), min./max. I/O unit sizes: 2048 bytes/2048 bytes <5>[ 12.468847] UBIFS (ubi0:1): FS size: 227160064 bytes (216 MiB, 1789 LEBs), journal size 11427840 bytes (10 MiB, 90 LEBs) <5>[ 12.490482] UBIFS (ubi0:1): reserved for root: 4952683 bytes (4836 KiB) <5>[ 12.503647] UBIFS (ubi0:1): media format: w4/r0 (latest is w5/r0), UUID 1F66C89D-FDD6-4471-A309-2A1153E8A4C8, small LPT model <14>[ 12.527623] block: attempting to load /tmp/ubifs_cfg/upper/etc/config/fstab <14>[ 12.551419] block: extroot: not configured <5>[ 12.590271] UBIFS (ubi0:1): un-mount UBI device 0 <5>[ 12.599647] UBIFS (ubi0:1): background thread "ubifs_bgt0_1" stops <5>[ 12.617946] UBIFS (ubi0:1): background thread "ubifs_bgt0_1" started, PID 473 <5>[ 12.765184] UBIFS (ubi0:1): UBIFS: mounted UBI device 0, volume 1, name "rootfs_data" <5>[ 12.780794] UBIFS (ubi0:1): LEB size: 126976 bytes (124 KiB), min./max. I/O unit sizes: 2048 bytes/2048 bytes <5>[ 12.800531] UBIFS (ubi0:1): FS size: 227160064 bytes (216 MiB, 1789 LEBs), journal size 11427840 bytes (10 MiB, 90 LEBs) <5>[ 12.822167] UBIFS (ubi0:1): reserved for root: 4952683 bytes (4836 KiB) <5>[ 12.835332] UBIFS (ubi0:1): media format: w4/r0 (latest is w5/r0), UUID 1F66C89D-FDD6-4471-A309-2A1153E8A4C8, small LPT model <14>[ 13.105964] block: attempting to load /tmp/ubifs_cfg/upper/etc/config/fstab <14>[ 13.128693] block: extroot: not configured <14>[ 13.193397] mount_root: switching to ubifs overlay <12>[ 13.246045] urandom-seed: Seeding with /etc/urandom.seed <6>[ 13.353193] mtk_soc_eth 1e100000.ethernet: 0x100 = 0x6060000c, 0x10c = 0x80818 <14>[ 13.375239] procd: - early - <14>[ 13.381113] procd: - watchdog - <14>[ 14.030208] procd: - watchdog - <14>[ 14.036773] procd: - ubus - <5>[ 14.124886] random: ubusd: uninitialized urandom read (4 bytes read) <5>[ 14.141149] random: ubusd: uninitialized urandom read (4 bytes read) <5>[ 14.154270] random: ubusd: uninitialized urandom read (4 bytes read) <14>[ 14.167802] procd: - init - <14>[ 15.243934] kmodloader: loading kernel modules from /etc/modules.d/* <6>[ 15.266742] sit: IPv6, IPv4 and MPLS over IPv4 tunneling driver <14>[ 15.377103] urngd: v1.0.2 started. <6>[ 15.378128] ip6_tables: (C) 2000-2006 Netfilter Core Team <6>[ 15.402802] Netfilter messages via NETLINK v0.30. <6>[ 15.414998] ip_set: protocol 6 <6>[ 15.453488] Mirror/redirect action on <6>[ 15.473202] u32 classifier <6>[ 15.478646] input device check on <6>[ 15.486012] Actions configured <6>[ 15.511782] nf_conntrack version 0.5.0 (4096 buckets, 16384 max) <5>[ 15.538082] Bridge firewalling registered <6>[ 15.550673] ip_tables: (C) 2000-2006 Netfilter Core Team <6>[ 15.615026] ctnetlink v0.93: registering with nfnetlink. <5>[ 15.621042] random: crng init done <5>[ 15.632549] random: 6 urandom warning(s) missed due to ratelimiting <6>[ 15.744028] wireguard: WireGuard 1.0.20200611 loaded. See www.wireguard.com for information. <6>[ 15.761011] wireguard: Copyright (C) 2015-2019 Jason A. Donenfeld <Jason@zx2c4.com>. All Rights Reserved. <6>[ 15.834038] xt_time: kernel timezone is -0000 <6>[ 15.858288] PPP generic driver version 2.4.2 <6>[ 15.869391] NET: Registered protocol family 24 <14>[ 15.882534] kmodloader: done loading kernel modules from /etc/modules.d/* <6>[ 22.699616] mtk_soc_eth 1e100000.ethernet: PPE started <6>[ 22.718875] br-lan: port 1(eth0.1) entered blocking state <6>[ 22.730002] br-lan: port 1(eth0.1) entered disabled state <6>[ 22.741541] device eth0.1 entered promiscuous mode <6>[ 22.751223] device eth0 entered promiscuous mode <6>[ 22.764586] br-lan: port 1(eth0.1) entered blocking state <6>[ 22.775424] br-lan: port 1(eth0.1) entered forwarding state <6>[ 22.787226] IPv6: ADDRCONF(NETDEV_UP): br-lan: link is not ready <6>[ 23.710555] IPv6: ADDRCONF(NETDEV_CHANGE): br-lan: link becomes ready <6>[ 717.323641] nf_conntrack: default automatic helper assignment has been turned off for security reasons and CT-based firewall rule not found. Use the iptables CT target to attach helpers instead. <1>[64037.837093] CPU 3 Unable to handle kernel paging request at virtual address 017f4eec, epc == 8006bf1c, ra == 8006be90 <4>[64037.858236] Oops[#1]: <4>[64037.862751] CPU: 3 PID: 0 Comm: swapper/3 Not tainted 4.14.209 #0 <4>[64037.874865] task: 8fc3cc80 task.stack: 8fc68000 <4>[64037.883863] $ 0 : 00000000 00000001 0000000c 81249bc0 <4>[64037.894263] $ 4 : 00000002 00100000 00614c15 00614c15 <4>[64037.904664] $ 8 : 0000ffff ffff0000 00000002 8de4b080 <4>[64037.915076] $12 : 8febb900 8febb944 804d06fc 00000001 <4>[64037.925483] $16 : 8fd7ce7c 81240320 8054c1e8 00100000 <4>[64037.935880] $20 : 017f4eec 8fd7cc3c 0000001f 8df75f00 <4>[64037.946274] $24 : 6bbf3ed6 00000000 <4>[64037.956675] $28 : 8fc68000 8fc0fc10 8fc0fca4 8006be90 <4>[64037.967094] Hi : 00000000 <4>[64037.972813] Lo : 00000000 <4>[64037.978530] epc : 8006bf1c 0x8006bf1c <4>[64037.986146] ra : 8006be90 0x8006be90 <4>[64037.993761] Status: 11007c03 KERNEL EXL IE <4>[64038.002081] Cause : c080000c (ExcCode 03) <4>[64038.010041] BadVA : 017f4eec <4>[64038.015756] PrId : 0001992f (MIPS 1004Kc) <4>[64038.023890] Modules linked in: pppoe ppp_async pppox ppp_generic nf_nat_pptp nf_conntrack_pptp nf_conntrack_ipv6 iptable_nat ipt_REJECT ipt_MASQUERADE xt_time xt_tcpudp xt_tcpmss xt_statistic xt_state xt_recent xt_nat xt_multiport xt_mark xt_mac xt_limit xt_length xt_hl xt_helper xt_ecn xt_dscp xt_conntrack xt_connmark xt_connlimit xt_connbytes xt_comment xt_TCPMSS xt_REDIRECT xt_LOG xt_HL xt_FLOWOFFLOAD xt_DSCP xt_CT xt_CLASSIFY wireguard ts_fsm ts_bm slhc nf_reject_ipv4 nf_nat_tftp nf_nat_snmp_basic nf_nat_sip nf_nat_redirect nf_nat_proto_gre nf_nat_masquerade_ipv4 nf_nat_irc nf_conntrack_ipv4 nf_nat_ipv4 nf_nat_h323 nf_nat_amanda nf_nat nf_log_ipv4 nf_flow_table_hw nf_flow_table nf_defrag_ipv6 nf_defrag_ipv4 nf_conntrack_tftp nf_conntrack_snmp nf_conntrack_sip nf_conntrack_rtcache nf_conntrack_proto_gre <4>[64038.166184] nf_conntrack_netlink nf_conntrack_irc nf_conntrack_h323 nf_conntrack_broadcast ts_kmp nf_conntrack_amanda iptable_raw iptable_mangle iptable_filter ipt_ECN ip_tables crc_ccitt br_netfilter sch_cake act_connmark nf_conntrack sch_tbf sch_ingress sch_htb sch_hfsc em_u32 cls_u32 cls_tcindex cls_route cls_matchall cls_fw cls_flow cls_basic act_skbedit act_mirred xt_set ip_set_list_set ip_set_hash_netportnet ip_set_hash_netport ip_set_hash_netnet ip_set_hash_netiface ip_set_hash_net ip_set_hash_mac ip_set_hash_ipportnet ip_set_hash_ipportip ip_set_hash_ipport ip_set_hash_ipmark ip_set_hash_ip ip_set_bitmap_port ip_set_bitmap_ipmac ip_set_bitmap_ip ip_set nfnetlink nf_log_ipv6 nf_log_common ip6table_mangle ip6table_filter ip6_tables ip6t_REJECT x_tables nf_reject_ipv6 ifb ip6_udp_tunnel udp_tunnel <4>[64038.307953] sit tunnel4 ip_tunnel usb_storage leds_gpio sd_mod scsi_mod gpio_button_hotplug f2fs ext4 mbcache jbd2 usbcore nls_base usb_common crc32c_generic crc32_generic <4>[64038.338634] Process swapper/3 (pid: 0, threadinfo=8fc68000, task=8fc3cc80, tls=00000000) <4>[64038.354718] Stack : 00000000 00000000 8ecdbd20 8fd7cc00 8fc0fc84 8fd7cc00 8e8e9b78 8fd7cc00 <4>[64038.371349] 8e8e9b80 8f30dc00 8fd7ce7c 8eaada6c 00000000 00000000 00000000 00000002 <4>[64038.387975] 8fc0fd48 8ecdbd20 8fc0fca0 8df815d0 8dd51ca4 8ecdbd90 8fd7cc00 8e8e9870 <4>[64038.404604] 00000001 00000000 8fc0fca0 8eb94600 00000000 8df75f00 8ebbdd00 803f1870 <4>[64038.421231] 00000100 00000002 00000001 8eb94600 8df81358 8df815b0 8ddb2800 8df80000 <4>[64038.437862] ... <4>[64038.442722] Call Trace: <4>[64038.442818] [<8eaada6c>] 0x8eaada6c [nf_flow_table@8eaac000+0x3370] <4>[64038.460142] [<8e8e9870>] 0x8e8e9870 [xt_FLOWOFFLOAD@8e8e9000+0xc10] <4>[64038.472616] [<803f1870>] 0x803f1870 <4>[64038.479573] [<8e91561c>] 0x8e91561c [ip_tables@8e914000+0x2b30] <4>[64038.491353] [<80364514>] 0x80364514 <4>[64038.498332] [<8e910000>] 0x8e910000 [ip_tunnel@8e910000+0x2c20] <4>[64038.510136] [<8e8403f0>] 0x8e8403f0 [nf_conntrack@8e840000+0x10770] <4>[64038.522619] [<803a0a78>] 0x803a0a78 <4>[64038.529574] [<803aa688>] 0x803aa688 <4>[64038.536531] [<803aa220>] 0x803aa220 <4>[64038.543468] [<803a94d8>] 0x803a94d8 <4>[64038.550395] [<803a8a40>] 0x803a8a40 <4>[64038.557330] [<8036270c>] 0x8036270c <4>[64038.564265] [<80011860>] 0x80011860 <4>[64038.571196] [<803629e8>] 0x803629e8 <4>[64038.578149] [<803652b0>] 0x803652b0 <4>[64038.585076] [<80078510>] 0x80078510 <4>[64038.592014] [<804a4898>] 0x804a4898 <4>[64038.598945] [<80033164>] 0x80033164 <4>[64038.605871] [<8025b4c0>] 0x8025b4c0 <4>[64038.612816] [<80007488>] 0x80007488 <4>[64038.619744] <4>[64038.622691] Code: 0282a021 0283a021 0000000f <10000001> ae910000 8e220004 0000000f 1040fffd 00000000 <4>[64038.642098] <4>[64038.645454] ---[ end trace 1f417dae2c6e7324 ]--- </code>

vincejv · December 12, 2023, 7:24pm

I'm still encountering this on 23.05.2, and apparently only the main disk or /dev/sda is affected, my other mounts are perfect responsive in /dev/sdb through FTP, but any IO operation against /dev/sda just cause the service to hang including FTP

I hardly think this is a hardware issue, as the IO Freeze can simply be fixed by plugging a new USB Device (USB Keyboard, Flashdrive, Card reader), after plugging everything in /dev/sda magically responds again. What comes to mind when plugging a new usb is it trigger a kernel interrupt, so likely a kernel interrupt bug.

Kernel Logs (before and after the freeze)

[  +0.086481] br-23f6a949a670: port 19(vethd59145d) entered blocking state
[  +0.007997] br-23f6a949a670: port 19(vethd59145d) entered disabled state
[  +0.008072] device vethd59145d entered promiscuous mode
[  +0.006594] br-23f6a949a670: port 19(vethd59145d) entered blocking state
[  +0.007481] br-23f6a949a670: port 19(vethd59145d) entered forwarding state
[  +0.190794] eth0: renamed from vethe6f88bf
[  +0.059764] IPv6: ADDRCONF(NETDEV_CHANGE): vethd59145d: link becomes ready
[Dec13 01:34] TCP: request_sock_TCP: Possible SYN flooding on port 5000. Sending cookies.  Check SNMP counters.
[Dec13 03:10] usb 1-1.4: new low-speed USB device number 3 using ehci-pci
[  +0.158902] input: USB usb keyboard as /devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.4/1-1.4:1.0/0003:C0F4:07C0.0001/input/input7
[  +0.081203] hid-generic 0003:C0F4:07C0.0001: input,hidraw0: USB HID v1.10 Keyboard [USB usb keyboard] on usb-0000:00:1a.0-1.4/input0
[  +0.016169] input: USB usb keyboard Consumer Control as /devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.4/1-1.4:1.1/0003:C0F4:07C0.0002/input/input8
[  +0.083995] input: USB usb keyboard System Control as /devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.4/1-1.4:1.1/0003:C0F4:07C0.0002/input/input9
[  +0.015220] hid-generic 0003:C0F4:07C0.0002: input,hidraw1: USB HID v1.10 Device [USB usb keyboard] on usb-0000:00:1a.0-1.4/input1

Syslog

Wed Dec 13 01:33:00 2023 daemon.info dnsmasq-dhcp[1]: DHCPACK(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 01:33:00 2023 user.notice nft-qos-monitor: ACTION=update, MACADDR=3c:19:cb:01:28:6d, IPADDR=172.16.0.58, HOSTNAME=Pictor
Wed Dec 13 01:33:00 2023 user.notice nft-qos-dynamic: ACTION=update, MACADDR=3c:19:cb:01:28:6d, IPADDR=172.16.0.58, HOSTNAME=Pictor
Wed Dec 13 03:10:49 2023 kern.info kernel: [12486.710062] usb 1-1.4: new low-speed USB device number 3 using ehci-pci
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) 94:17:00:20:a3:1d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 172.16.0.43 94:17:00:20:a3:1d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPREQUEST(br-lan) 172.16.0.43 94:17:00:20:a3:1d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPACK(br-lan) 172.16.0.43 94:17:00:20:a3:1d M2006C3LG-Redmi9A
Wed Dec 13 03:10:49 2023 user.notice nft-qos-monitor: ACTION=add, MACADDR=94:17:00:20:a3:1d, IPADDR=172.16.0.43, HOSTNAME=M2006C3LG-Redmi9A
Wed Dec 13 03:10:49 2023 user.notice nft-qos-dynamic: ACTION=add, MACADDR=94:17:00:20:a3:1d, IPADDR=172.16.0.43, HOSTNAME=M2006C3LG-Redmi9A
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPREQUEST(br-lan) 172.16.0.42 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPACK(br-lan) 172.16.0.42 0a:97:77:02:ce:64 OPPO-A52
Wed Dec 13 03:10:49 2023 user.notice nft-qos-monitor: ACTION=update, MACADDR=0a:97:77:02:ce:64, IPADDR=172.16.0.42, HOSTNAME=OPPO-A52
Wed Dec 13 03:10:49 2023 user.notice nft-qos-dynamic: ACTION=update, MACADDR=0a:97:77:02:ce:64, IPADDR=172.16.0.42, HOSTNAME=OPPO-A52
Wed Dec 13 03:10:49 2023 authpriv.notice sudo:     root : TTY=pts/6 ; PWD=/root ; USER=root ; COMMAND=/bin/ping 185.148.1.127
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPREQUEST(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.err uhttpd[4151]: [info] luci: accepted login on / for root from 127.0.0.1
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPACK(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPREQUEST(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPACK(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPREQUEST(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPACK(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPREQUEST(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPACK(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPREQUEST(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPACK(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPREQUEST(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPACK(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPREQUEST(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPACK(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPREQUEST(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPACK(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPREQUEST(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPACK(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPREQUEST(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPACK(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPREQUEST(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPACK(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPREQUEST(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPACK(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPREQUEST(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPACK(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPREQUEST(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPACK(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPREQUEST(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPACK(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPREQUEST(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPACK(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPREQUEST(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPACK(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPREQUEST(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPACK(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPREQUEST(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPACK(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPREQUEST(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPACK(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPREQUEST(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPACK(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPREQUEST(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPACK(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPREQUEST(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPACK(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPREQUEST(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPACK(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 172.16.0.58 3c:19:cb:01:28:6d
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPREQUEST(br-lan) 172.16.0.42 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPACK(br-lan) 172.16.0.42 0a:97:77:02:ce:64 OPPO-A52
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPREQUEST(br-lan) 172.16.0.42 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPACK(br-lan) 172.16.0.42 0a:97:77:02:ce:64 OPPO-A52
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPREQUEST(br-lan) 172.16.0.42 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPACK(br-lan) 172.16.0.42 0a:97:77:02:ce:64 OPPO-A52
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 172.16.0.42 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 172.16.0.42 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 172.16.0.42 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 172.16.0.42 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPREQUEST(br-lan) 172.16.0.42 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPACK(br-lan) 172.16.0.42 0a:97:77:02:ce:64 OPPO-A52
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPREQUEST(br-lan) 172.16.0.42 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPACK(br-lan) 172.16.0.42 0a:97:77:02:ce:64 OPPO-A52
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPREQUEST(br-lan) 172.16.0.42 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPACK(br-lan) 172.16.0.42 0a:97:77:02:ce:64 OPPO-A52
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 172.16.0.42 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 172.16.0.42 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 172.16.0.42 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 172.16.0.42 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPREQUEST(br-lan) 172.16.0.42 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPACK(br-lan) 172.16.0.42 0a:97:77:02:ce:64 OPPO-A52
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPREQUEST(br-lan) 172.16.0.42 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPACK(br-lan) 172.16.0.42 0a:97:77:02:ce:64 OPPO-A52
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPREQUEST(br-lan) 172.16.0.42 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPACK(br-lan) 172.16.0.42 0a:97:77:02:ce:64 OPPO-A52
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 172.16.0.42 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 172.16.0.42 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 172.16.0.42 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 172.16.0.42 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPREQUEST(br-lan) 172.16.0.42 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPACK(br-lan) 172.16.0.42 0a:97:77:02:ce:64 OPPO-A52
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPREQUEST(br-lan) 172.16.0.42 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPACK(br-lan) 172.16.0.42 0a:97:77:02:ce:64 OPPO-A52
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPREQUEST(br-lan) 172.16.0.42 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPACK(br-lan) 172.16.0.42 0a:97:77:02:ce:64 OPPO-A52
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 172.16.0.42 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 172.16.0.42 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 172.16.0.42 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 172.16.0.42 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPREQUEST(br-lan) 172.16.0.42 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPACK(br-lan) 172.16.0.42 0a:97:77:02:ce:64 OPPO-A52
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPREQUEST(br-lan) 172.16.0.42 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPACK(br-lan) 172.16.0.42 0a:97:77:02:ce:64 OPPO-A52
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPREQUEST(br-lan) 172.16.0.42 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPACK(br-lan) 172.16.0.42 0a:97:77:02:ce:64 OPPO-A52
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 172.16.0.42 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 172.16.0.42 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 172.16.0.42 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 172.16.0.42 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPREQUEST(br-lan) 172.16.0.42 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPACK(br-lan) 172.16.0.42 0a:97:77:02:ce:64 OPPO-A52
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPREQUEST(br-lan) 172.16.0.42 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPACK(br-lan) 172.16.0.42 0a:97:77:02:ce:64 OPPO-A52
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPREQUEST(br-lan) 172.16.0.42 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPACK(br-lan) 172.16.0.42 0a:97:77:02:ce:64 OPPO-A52
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 172.16.0.42 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 172.16.0.42 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 172.16.0.42 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPDISCOVER(br-lan) 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPOFFER(br-lan) 172.16.0.42 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPREQUEST(br-lan) 172.16.0.42 0a:97:77:02:ce:64
Wed Dec 13 03:10:49 2023 daemon.info dnsmasq-dhcp[1]: DHCPACK(br-lan) 172.16.0.42 0a:97:77:02:ce:64 OPPO-A52
Wed Dec 13 03:10:49 2023 user.notice nft-qos-monitor: ACTION=update, MACADDR=3c:19:cb:01:28:6d, IPADDR=172.16.0.58, HOSTNAME=Pictor
Wed Dec 13 03:10:50 2023 user.notice nft-qos-monitor: ACTION=update, MACADDR=3c:19:cb:01:28:6d, IPADDR=172.16.0.58, HOSTNAME=Pictor
Wed Dec 13 03:10:50 2023 kern.info kernel: [12487.065551] hid-generic 0003:C0F4:07C0.0002: input,hidraw1: USB HID v1.10 Device [USB usb keyboard] on usb-0000:00:1a.0-1.4/input1
Wed Dec 13 03:10:50 2023 user.notice nft-qos-dynamic: ACTION=update, MACADDR=3c:19:cb:01:28:6d, IPADDR=172.16.0.58, HOSTNAME=Pictor
Wed Dec 13 03:10:50 2023 user.notice nft-qos-monitor: ACTION=update, MACADDR=3c:19:cb:01:28:6d, IPADDR=172.16.0.58, HOSTNAME=Pictor
Wed Dec 13 03:10:50 2023 user.notice nft-qos-dynamic: ACTION=update, MACADDR=3c:19:cb:01:28:6d, IPADDR=172.16.0.58, HOSTNAME=Pictor
Wed Dec 13 03:10:50 2023 user.notice nft-qos-monitor: ACTION=update, MACADDR=3c:19:cb:01:28:6d, IPADDR=172.16.0.58, HOSTNAME=Pictor
Wed Dec 13 03:10:50 2023 user.notice nft-qos-dynamic: ACTION=update, MACADDR=3c:19:cb:01:28:6d, IPADDR=172.16.0.58, HOSTNAME=Pictor
Wed Dec 13 03:10:50 2023 user.notice nft-qos-monitor: ACTION=update, MACADDR=3c:19:cb:01:28:6d, IPADDR=172.16.0.58, HOSTNAME=Pictor

As you can see from syslog, DHCP was unresponsive during the freeze (as the lease file is saved in /dev/sda2), but after plugging in a keyboard, DHCP spams the logs with lease requests as IO starts to recover, then DHCP magically works again.

vincejv · January 19, 2024, 8:41pm

Just to provide a more updated info, experimenting the scenarios of when the system will unfreeze (didn't use the USB method), the IO magically unfreezed after a couple of hours, here are the logs (notice the long time gap between the logs), smart stats are clean.

logread

Wed Jan 17 22:35:52 2024 daemon.err dockerd[6420]: time="2024-01-17T14:35:52.863293270Z" level=info msg="loading plugin \"io.containerd.internal.v1.shutdown\"..." runtime=io.containerd.runc.v2 type=io.containerd.internal.v1
Wed Jan 17 22:35:52 2024 daemon.err dockerd[6420]: time="2024-01-17T14:35:52.863311545Z" level=info msg="loading plugin \"io.containerd.ttrpc.v1.task\"..." runtime=io.containerd.runc.v2 type=io.containerd.ttrpc.v1
Wed Jan 17 22:35:52 2024 daemon.err dockerd[6420]: time="2024-01-17T14:35:52.863390429Z" level=info msg="loading plugin \"io.containerd.ttrpc.v1.pause\"..." runtime=io.containerd.runc.v2 type=io.containerd.ttrpc.v1
Wed Jan 17 22:35:52 2024 daemon.info ipsec: 12[NET] using forecast interface br-lan
Wed Jan 17 22:35:52 2024 daemon.info ipsec: 12[CFG] joining forecast multicast groups: 224.0.0.1,224.0.0.22,224.0.0.251,224.0.0.252,239.255.255.250
Wed Jan 17 22:35:53 2024 daemon.info ipsec: 10[KNL] interface veth2e621c5 deleted
Wed Jan 17 22:35:53 2024 kern.info kernel: [609739.225027] eth0: renamed from veth2e621c5
Wed Jan 17 22:35:53 2024 daemon.info ipsec: 10[KNL] interface veth707f6ba deleted
Thu Jan 18 18:56:04 2024 kern.err kernel: [682949.757885] ata4.00: irq_stat 0x40000008
Thu Jan 18 18:56:04 2024 daemon.info ipsec: 11[NET] using forecast interface br-lan
Thu Jan 18 18:56:04 2024 daemon.info ipsec: 11[CFG] joining forecast multicast groups: 224.0.0.1,224.0.0.22,224.0.0.251,224.0.0.252,239.255.255.250
Thu Jan 18 18:56:04 2024 daemon.info ipsec: 05[NET] using forecast interface br-lan
Thu Jan 18 18:56:04 2024 daemon.info ipsec: 05[CFG] joining forecast multicast groups: 224.0.0.1,224.0.0.22,224.0.0.251,224.0.0.252,239.255.255.250
Thu Jan 18 18:56:04 2024 daemon.info avahi-daemon[4521]: Joining mDNS multicast group on interface vethc7a8a0d.IPv6 with address fe80::108d:d3ff:febc:45ed.
Thu Jan 18 18:56:04 2024 daemon.info ipsec: 14[KNL] fe80::108d:d3ff:febc:45ed appeared on vethc7a8a0d
Thu Jan 18 18:56:04 2024 daemon.info avahi-daemon[4521]: New relevant interface vethc7a8a0d.IPv6 for mDNS.
Thu Jan 18 18:56:04 2024 daemon.info avahi-daemon[4521]: Registering new address record for fe80::108d:d3ff:febc:45ed on vethc7a8a0d.*.
Thu Jan 18 18:56:04 2024 daemon.info ipsec: 13[NET] using forecast interface br-lan
Thu Jan 18 18:56:04 2024 daemon.info ipsec: 13[CFG] joining forecast multicast groups: 224.0.0.1,224.0.0.22,224.0.0.251,224.0.0.252,239.255.255.250
Thu Jan 18 18:56:04 2024 daemon.info avahi-daemon[4521]: Joining mDNS multicast group on interface veth2bd4c67.IPv6 with address fe80::7c41:28ff:fe15:3607.
Thu Jan 18 18:56:04 2024 daemon.info ipsec: 15[KNL] fe80::7c41:28ff:fe15:3607 appeared on veth2bd4c67
Thu Jan 18 18:56:04 2024 daemon.info avahi-daemon[4521]: New relevant interface veth2bd4c67.IPv6 for mDNS.

dmesg

[36633.202233] eth0: renamed from veth3af5989
[36633.292088] IPv6: ADDRCONF(NETDEV_CHANGE): veth2f6374e: link becomes ready
[36633.300352] br-23f6a949a670: port 22(veth2f6374e) entered blocking state
[36633.308330] br-23f6a949a670: port 22(veth2f6374e) entered forwarding state
[42300.391275] ata4.00: exception Emask 0x0 SAct 0xd020003e SErr 0x0 action 0x0
[42300.399215] ata4.00: irq_stat 0x40000008

Anyways, I managed to fix the issue by forking the code and cherry-picking patches to upgrade to kernel 5.15.147, and the freezing issue seems to have been fixed, I have tried going for 6.1.71 as well (cherry-pick commit method), it also didn't have the same freezing issue. So I guess I'll wait for the team to release OpenWRT with a more updated Kernel, and I think there aren't any other reports regarding this as I have a fairly complex setup with my OpenWRT x86 system which includes docker + lxc + btrfs raid + etc, the installed packages probably triggered a kernel bug which a regular user won't notice.

And as per the latest logs provided the IO Unfreezed after encountering this log Thu Jan 18 18:56:04 2024 kern.err kernel: [682949.757885] ata4.00: irq_stat 0x40000008 which leads me to believe that it was an interrupt issue after all which may have been fixed on a later kernel version.

For parting words, I just wished the Kernel was less tightly integrated to the OpenWRT build system, as issues like these can simply be fixed by upgrading kernels + kmods, no need to wipe the rootfs. It's a lot of work to cherry pick + forking code which a casual user would find as a huge hassle.

qpon123 · January 20, 2024, 2:17pm

I'm having similar issues using an ASUS TUF-AX4200 (ARMv8 mediatek/filogic) with a USB pendrive attached to it as storage. Never tried adding another USB device to unfreeze it, usually I just reboot the router through luci to get it working again. The router has OpenWrt 23.05.2 with all the package updates installed, and after a couple of days uptime clients cannot connect to it anymore through wifi, and just as you described "still have routing, internet and pppoe enabled and connected, luci is still also responsive [...], SSH is also inaccessible". I have a dumb-AP connected to one of the local ethernet ports of the TUF-AX4200, and I can still log into luci through the dumb-AP. I would say this issue is not x86 specific.

vincejv · January 20, 2024, 5:33pm

Try that plugging/replugging the USB pendrive attached and see if it unfreezes it, or plugin a USB hub and attach a separate usb device and let us know what you see.

Yes, we have the same issue, new clients can't connect because the DHCP server may be storing the lease file in the disk, so DHCP won't function temporarily as the IO is frozen.

Anyways it's been a couple of days now on Kernel 6.1.71, no freezing issues so far...

Also a lot of EXT4/BTRFS fixes from 5.15.137 to .147, given this a disk io related issue, might have been fixed between those versions. I'm using both btrfs & ext4, it's the ext4 disk that's freezing.

qpon123 · January 22, 2024, 5:46pm

The file system on my USB pendrive is exfat. I've switched back to my previous Linksys EA8300 (ARMv7 ipq40xx/generic) router, installed a clean 23.05.2 and then all the latest software updates, and a lot of additional packages my configuration uses but this time I haven't added the USB pendrive to the router (and haven't installed the kmod-usb* packages either), and this freeze still occurred. The last entry in the system log was a mac flush kernel info from the ath10k module, and after that no more hostapd entries. New clients were unable to connect through wifi, ssh was not accepting connections, but luci is still up and accepting connections. I guess I see the same behavior but the root cause may be different on my routers.

elder_tinkerer · January 22, 2024, 6:36pm

With opkg upgrade or LuCI -> System -> Software -> Updates?
I do hope not.
If yes, on OpenWrt, that's a good way to brick your device.

qpon123 · January 22, 2024, 9:45pm

With the commands

opkg update
opkg list-upgradable | cut -f 1 -d ' ' | xargs opkg upgrade

I thought the package updates are safe to use.

elder_tinkerer · January 22, 2024, 10:46pm

As you might know, OpenWrt is no full-fledged, multi-purpose linux distribution.
So while it's normal and recommended for a standard linux distribution to do updates on a regular basis, which is often only a few updated libraries or a new kernel, this is not true for OpenWrt.
Please refer to this for further information.

qpon123 · January 23, 2024, 7:44am

Oh my, I didn't know about it, but now I learned it the hard way! Thank you for taking the time and pointing this out for me, I am going to "firstboot" my router right now.

vincejv · January 24, 2024, 3:57pm

It's definitely okay to upgrade packages in OpenWRT, but not the base packages like busybox, the details are here: To upgrade or not to upgrade packages - #11 by jow

Also upgrade maybe required if it's a security issue/fix listed here: https://openwrt.org/advisory/start

elder_tinkerer · January 25, 2024, 6:50pm

Well, that's jows opinion. I think he's right, but other people in the mentioned thread seem to have different opinions.
I think, i should be safe for single packages.

You might agree that it's not the best idea to upgrade all installed packages by just executing opkg upgrade or similar.

And of course, all these are recommendations.
People tend to have their own thoughts about other people's recommendations.

These are quite old (at least 15 months) and should've been fixed by a new release quite soon at that time.
But for a new security issue: I agree with that.

Another thing to think about:
All these updates would be installed into the overlay. If the router's memory is already sparse, it would worsen the situation. Or make it even impossible to install the updates.

qpon123 · January 27, 2024, 7:44am

I had the firstboot and the reconfiguration 3 days ago and there was no IO freeze for me since then. Neither on the ASUS TUF-AX4200 nor on the Linksys EA8300. Maybe it is too early to be 100% sure, 3 days uptime is not that much when usually I got the IO freeze in 1-2 days, but in my case it is highly likely that the package upgrade caused the issue. Right now opkg list-upgradable shows the following list:

luci-theme-bootstrap - git-23.306.39416-c86c256 - git-23.338.81541-94798fc
netifd - 2023-11-10-35facc83-1.1 - 2024-01-04-c18cc79d-1
luci-mod-status - git-23.306.52197-bdcd3e0 - git-23.351.85404-a962261
luci-app-firewall - git-23.306.38853-a0466cd - git-24.008.46353-971459d
luci-base - git-23.306.39416-c86c256 - git-24.006.68745-9128656
luci-proto-ipv6 - git-21.148.48881-79947af - git-23.355.78874-80140aa
luci-app-upnp - git-22.297.83017-2877753 - git-24.025.85485-89a9b58
luci-mod-network - git-23.313.56166-6da284d - git-24.025.85485-c30d85b
jsonfilter - 2018-02-04-c7e938d6-1 - 2024-01-23-594cfa86-1

So one or more of these are not recommended for upgrade. I guess the luci packages are for the web interface, the jsonfilter is quite new, so that netifd package is what I would consider, but this is just a guess, I have no proof.