This discussion has been locked.

You can no longer post new replies to this discussion. If you have a question you can start a new discussion

UTM HOME - Wireless "DMA failed to stop in 10 ms" filling logs and WIFI slow until power cycle

I've been having the following problem with my Home UTM for the better part of seven years - perhaps longer. Frequency varies, sometimes happening nightly, other times waiting months to recur, but ALWAYS recurs. Lately, the problem is chronic and reduces my WiFi to an unusable state daily.

The WiFi will slow down to <1Mbps and `wireless.log` begins filling up with logs like the following:

2023:12:22-08:38:41 A4002469308FE64 kernel: [ 1195.820000] ath: phy1: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x02100020 DMADBG_7=0x00006300
2023:12:22-08:38:43 A4002469308FE64 kernel: [ 1197.150000] ath: phy1: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x02100020 DMADBG_7=0x00006300
5684.wireless.log

Usually, I just roll my eyes and reboot the AP, but as this is now happening every day, multiple times a day, and sometimes is not fixed by a reboot of the AP anymore, I thought I should reach out for support.

Disclaimer: I know the AP15 is EOL, but it has usually been a reliable AP, and I think this problem occurred on my AP55 as well, which I believe is not EOL. I am currently living out of the country, and access to good tech is very hard to come by, so this combination of hardware will have to stay in service for the next few years.

This thread was automatically locked due to age.

Parents

0 gcracker 4 months ago

Things I have tried:

Setting the AP to Dynamic Channel/Auto when it was set to just Auto before
Deleting the AP and re-authorizing it
Deleting the Wireless Network and creating a new one

It seems to happen more often when I move a lot of data over the WiFi network. My partner just recently reinstalled her OS and synced about 80GB from Onedrive, and I switched online photo providers from Google Photos to Ente.io and pushed about 120GB up. The WiFi stability seems to suffer after these heavy uses of wireless.

In the log snippet below, you can see the DMA/TX error filling the log. I then power-cycle the AP15 and you can see the reboot process and return to "normal" funtion, but the error is still peppered in there, and will increase.

2023:12:23-08:09:36 A4002469308FE64 kernel: [32618.000000] ath: phy1: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x02100020 DMADBG_7=0x00006300
2023:12:23-08:09:37 A4002469308FE64 kernel: [32618.520000] ath: phy1: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x02100020 DMADBG_7=0x00006300
2023:12:23-08:09:38 A4002469308FE64 kernel: [32619.340000] ath: phy1: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x02100020 DMADBG_7=0x00006300
2023:12:23-08:09:38 A4002469308FE64 kernel: [32619.850000] ath: phy1: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x02100020 DMADBG_7=0x00006300
2023:12:23-08:09:39 A4002469308FE64 kernel: [32620.360000] ath: phy1: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x02100020 DMADBG_7=0x00006300
2023:12:13-16:40:57 A4002469308FE64 logread[970]: Logread connected to 10.100.200.1:415
2023:12:13-16:40:57 A4002469308FE64 kernel: [ 21.240000] br-lan: port 1(eth0) entered forwarding state
2023:12:23-08:10:30 tsiskwahi awed[27388]: [A4002469308FE64] ll_read: dead socket: Resource temporarily unavailable
2023:12:23-08:10:30 tsiskwahi awed[27388]: [A4002469308FE64] disconnected. Close socket and kill process.
2023:12:23-08:10:36 tsiskwahi awed[26865]: [MASTER] new connection from 10.100.200.8:52762
2023:12:23-08:10:36 tsiskwahi awed[24101]: [A4002469308FE64] AP15 from 10.100.200.8:52762 identified as A4002469308FE64
2023:12:23-08:10:36 tsiskwahi awed[24101]: [A4002469308FE64] (Re-)loaded identity and/or configuration
2023:12:13-16:41:10 A4002469308FE64 aweclient[887]: Cloudclient not found on ubus.
2023:12:13-16:41:12 A4002469308FE64 add_radio_mapping.sh: AP15 detected: Using on-the-fly ACS procedure
2023:12:13-16:41:12 A4002469308FE64 netifd: Interface 'vxlan' is enabled
2023:12:13-16:41:12 A4002469308FE64 netifd: Network device 'vxlan' link is up
2023:12:13-16:41:12 A4002469308FE64 netifd: Interface 'vxlan' has link connectivity
2023:12:13-16:41:12 A4002469308FE64 netifd: Interface 'vxlan' is setting up now
2023:12:13-16:41:12 A4002469308FE64 netifd: Interface 'vxlan' is now up
2023:12:13-16:41:12 A4002469308FE64 pdog[739]: src/process.c:325/unregister_process: process with name hostapd-phy1 is not registered before
2023:12:13-16:41:12 A4002469308FE64 netifd: radio0 (1275): {
2023:12:13-16:41:12 A4002469308FE64 netifd: radio0 (1275): "result": "FAILURE"
2023:12:13-16:41:12 A4002469308FE64 netifd: radio0 (1275): }
2023:12:13-16:41:13 A4002469308FE64 netifd: radio0 (1275): Configuration file: /var/run/hostapd-phy1.conf
2023:12:13-16:41:13 A4002469308FE64 netifd: radio0 (1275): eapol_version=1
2023:12:13-16:41:13 A4002469308FE64 netifd: radio0 (1275): nl80211: TDLS supported
2023:12:13-16:41:13 A4002469308FE64 netifd: radio0 (1275): nl80211: TDLS external setup
2023:12:13-16:41:13 A4002469308FE64 netifd: radio0 (1275): nl80211: Supported cipher 00-0f-ac:1
2023:12:13-16:41:13 A4002469308FE64 netifd: radio0 (1275): nl80211: Supported cipher 00-0f-ac:5
2023:12:13-16:41:13 A4002469308FE64 netifd: radio0 (1275): nl80211: Supported cipher 00-0f-ac:2
2023:12:13-16:41:13 A4002469308FE64 netifd: radio0 (1275): nl80211: Supported cipher 00-0f-ac:4
2023:12:13-16:41:13 A4002469308FE64 netifd: radio0 (1275): nl80211: Supported cipher 00-0f-ac:10
2023:12:13-16:41:13 A4002469308FE64 netifd: radio0 (1275): nl80211: Supported cipher 00-0f-ac:8
2023:12:13-16:41:13 A4002469308FE64 netifd: radio0 (1275): nl80211: Supported cipher 00-0f-ac:9
2023:12:13-16:41:13 A4002469308FE64 netifd: radio0 (1275): nl80211: Supported cipher 00-0f-ac:6
2023:12:13-16:41:13 A4002469308FE64 netifd: radio0 (1275): nl80211: Supported cipher 00-0f-ac:13
2023:12:13-16:41:13 A4002469308FE64 netifd: radio0 (1275): nl80211: Supported cipher 00-0f-ac:11
2023:12:13-16:41:13 A4002469308FE64 netifd: radio0 (1275): nl80211: Supported cipher 00-0f-ac:12
2023:12:13-16:41:13 A4002469308FE64 netifd: radio0 (1275): nl80211: Using driver-based off-channel TX
2023:12:13-16:41:13 A4002469308FE64 netifd: radio0 (1275): nl80211: Use separate P2P group interface (driver advertised support)
2023:12:13-16:41:13 A4002469308FE64 netifd: radio0 (1275): nl80211: interface wlan0 in phy phy1
2023:12:13-16:41:13 A4002469308FE64 netifd: radio0 (1275): nl80211: Set mode ifindex 6 iftype 3 (AP)
2023:12:13-16:41:13 A4002469308FE64 netifd: radio0 (1275): nl80211: Setup AP(wlan0) - device_ap_sme=0 use_monitor=0
2023:12:13-16:41:13 A4002469308FE64 netifd: radio0 (1275): nl80211: Subscribe to mgmt frames with AP handle 0xaa62d8
2023:12:13-16:41:13 A4002469308FE64 netifd: radio0 (1275): nl80211: Register frame type=0xb0 (WLAN_FC_STYPE_AUTH) nl_handle=0xaa62d8 match=
2023:12:13-16:41:13 A4002469308FE64 netifd: radio0 (1275): nl80211: Register frame type=0x0 (WLAN_FC_STYPE_ASSOC_REQ) nl_handle=0xaa62d8 match=
2023:12:13-16:41:13 A4002469308FE64 netifd: radio0 (1275): nl80211: Register frame type=0x20 (WLAN_FC_STYPE_REASSOC_REQ) nl_handle=0xaa62d8 match=
2023:12:13-16:41:13 A4002469308FE64 netifd: radio0 (1275): nl80211: Register frame type=0xa0 (WLAN_FC_STYPE_DISASSOC) nl_handle=0xaa62d8 match=
2023:12:13-16:41:13 A4002469308FE64 netifd: radio0 (1275): nl80211: Register frame type=0xc0 (WLAN_FC_STYPE_DEAUTH) nl_handle=0xaa62d8 match=
2023:12:13-16:41:13 A4002469308FE64 netifd: radio0 (1275): nl80211: Register frame type=0xd0 (WLAN_FC_STYPE_ACTION) nl_handle=0xaa62d8 match=
2023:12:13-16:41:13 A4002469308FE64 netifd: radio0 (1275): nl80211: Register frame type=0x40 (WLAN_FC_STYPE_PROBE_REQ) nl_handle=0xaa62d8 match=
2023:12:13-16:41:13 A4002469308FE64 netifd: radio0 (1275): nl80211: Add own interface ifindex 4
2023:12:13-16:41:13 A4002469308FE64 netifd: radio0 (1275): nl80211: if_indices[16]: 4
2023:12:13-16:41:13 A4002469308FE64 netifd: radio0 (1275): nl80211: Add own interface ifindex 6
2023:12:13-16:41:13 A4002469308FE64 netifd: radio0 (1275): nl80211: if_indices[16]: 4 6
2023:12:13-16:41:13 A4002469308FE64 netifd: radio0 (1275): nl80211: Adding interface wlan0 into bridge br-lan
2023:12:13-16:41:13 A4002469308FE64 kernel: [ 36.430000] device wlan0 entered promiscuous mode
2023:12:13-16:41:13 A4002469308FE64 kernel: [ 36.440000] ath: phy1: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x02100020 DMADBG_7=0x00006300
2023:12:13-16:41:13 A4002469308FE64 netifd: radio0 (1275): phy: phy1
2023:12:13-16:41:13 A4002469308FE64 netifd: radio0 (1275): BSS count 1, BSSID mask 00:00:00:00:00:00 (0 bits)
2023:12:13-16:41:13 A4002469308FE64 netifd: radio0 (1275): wlan0: interface state UNINITIALIZED->COUNTRY_UPDATE
2023:12:13-16:41:13 A4002469308FE64 netifd: radio0 (1275): Previous country code BZ, new country code BZ
2023:12:13-16:41:13 A4002469308FE64 netifd: radio0 (1275): nl80211: Regulatory information - country=BZ (DFS-JP)
2023:12:13-16:41:13 A4002469308FE64 netifd: radio0 (1275): nl80211: 2402-2482 @ 40 MHz 30 mBm
2023:12:13-16:41:13 A4002469308FE64 netifd: radio0 (1275): nl80211: 5735-5835 @ 80 MHz 30 mBm
2023:12:13-16:41:13 A4002469308FE64 netifd: radio0 (1275): nl80211: Added 802.11b mode based on 802.11g information
2023:12:13-16:41:13 A4002469308FE64 netifd: radio0 (1275): Allowed channel: mode=1 chan=1 freq=2412 MHz max_tx_power=30 dBm
2023:12:13-16:41:13 A4002469308FE64 netifd: radio0 (1275): Allowed channel: mode=1 chan=2 freq=2417 MHz max_tx_power=30 dBm
2023:12:13-16:41:13 A4002469308FE64 netifd: radio0 (1275): Allowed channel: mode=1 chan=3 freq=2422 MHz max_tx_power=30 dBm
2023:12:13-16:41:13 A4002469308FE64 kernel: [ 36.590000] ath: phy1: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x02100020 DMADBG_7=0x00006300
2023:12:13-16:41:13 A4002469308FE64 netifd: lan (933): Performing a DHCP renew
2023:12:13-16:41:13 A4002469308FE64 netifd: lan (933): Sending renew...
2023:12:13-16:41:13 A4002469308FE64 netifd: lan (933): Lease of 10.100.200.8 obtained, lease time 28800
2023:12:13-16:41:14 A4002469308FE64 kernel: [ 37.850000] ath: phy1: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x02100020 DMADBG_7=0x00006300
2023:12:13-16:41:14 A4002469308FE64 aweclient[887]: aweclient.c (1882) A signal received during select.
2023:12:13-16:41:15 A4002469308FE64 kernel: [ 39.110000] ath: phy1: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x02100020 DMADBG_7=0x00006300
2023:12:13-16:41:17 A4002469308FE64 kernel: [ 40.370000] ath: phy1: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x02100020 DMADBG_7=0x00006300
2023:12:13-16:41:18 A4002469308FE64 kernel: [ 41.630000] ath: phy1: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x02100020 DMADBG_7=0x00006300
2023:12:13-16:41:19 A4002469308FE64 kernel: [ 42.850000] ath: phy1: DMA failed to stop in 10 ms AR_CR=0x00000024 AR_DIAG_SW=0x02000020 DMADBG_7=0x00006300
2023:12:13-16:41:19 A4002469308FE64 kernel: [ 43.100000] br-lan: port 2(wlan0) entered forwarding state
2023:12:13-16:41:19 A4002469308FE64 kernel: [ 43.100000] br-lan: port 2(wlan0) entered forwarding state
2023:12:13-16:41:19 A4002469308FE64 netifd: Network device 'wlan0' link is up
2023:12:13-16:41:21 A4002469308FE64 kernel: [ 45.100000] br-lan: port 2(wlan0) entered forwarding state
2023:12:13-16:41:28 A4002469308FE64 hostapd: wlan0: STA 3c:28:6d:22:33:27 IEEE 802.11: authenticated
2023:12:13-16:41:28 A4002469308FE64 hostapd: wlan0: STA 3c:28:6d:22:33:27 IEEE 802.11: associated (aid 1)
2023:12:13-16:41:28 A4002469308FE64 awelogger[1375]: id="4103" severity="info" sys="System" sub="WiFi" name="STA authentication" ssid="rampuss_nomap" ssid_id="WLAN1.0" bssid="00:1a:8c:7f:bc:c4" sta="3c:28:6d:22:33:27" status_code="0"
2023:12:13-16:41:28 A4002469308FE64 awelogger[1375]: id="4104" severity="info" sys="System" sub="WiFi" name="STA association" ssid="rampuss_nomap" ssid_id="WLAN1.0" bssid="00:1a:8c:7f:bc:c4" sta="3c:28:6d:22:33:27" status_code="0"
2023:12:13-16:41:28 A4002469308FE64 hostapd: wlan0: STA 3c:28:6d:22:33:27 RADIUS: starting accounting session 61B777AF-00000000
2023:12:13-16:41:28 A4002469308FE64 hostapd: wlan0: STA 3c:28:6d:22:33:27 WPA: pairwise key handshake completed (RSN)
2023:12:13-16:41:28 A4002469308FE64 awelogger[1375]: id="4101" severity="info" sys="System" sub="WiFi" name="STA connected" ssid="rampuss_nomap" ssid_id="WLAN1.0" bssid="00:1a:8c:7f:bc:c4" sta="3c:28:6d:22:33:27"
2023:12:13-16:41:33 A4002469308FE64 kernel: [ 56.830000] random: nonblocking pool is initialized
2023:12:23-08:11:00 tsiskwahi awed[26865]: [MASTER] updating confd object for AP A4002469308FE64 with new channels (6 -> 5)
2023:12:23-08:11:00 tsiskwahi awed[26865]: [MASTER] start processing configuration change
2023:12:23-08:11:00 tsiskwahi awed[26865]: [MASTER] end processing configuration change
2023:12:23-08:11:37 A4002469308FE64 hostapd: wlan0: STA 3c:28:6d:ea:ad:ea IEEE 802.11: authenticated
2023:12:23-08:11:37 A4002469308FE64 hostapd: wlan0: STA 3c:28:6d:ea:ad:ea IEEE 802.11: associated (aid 2)
2023:12:23-08:11:37 A4002469308FE64 hostapd: wlan0: STA 3c:28:6d:ea:ad:ea RADIUS: starting accounting session 61B777AF-00000001
2023:12:23-08:11:37 A4002469308FE64 hostapd: wlan0: STA 3c:28:6d:ea:ad:ea WPA: pairwise key handshake completed (RSN)
2023:12:23-08:11:37 A4002469308FE64 awelogger[1375]: id="4103" severity="info" sys="System" sub="WiFi" name="STA authentication" ssid="rampuss_nomap" ssid_id="WLAN1.0" bssid="00:1a:8c:7f:bc:c4" sta="3c:28:6d:ea:ad:ea" status_code="0"
2023:12:23-08:11:37 A4002469308FE64 awelogger[1375]: id="4104" severity="info" sys="System" sub="WiFi" name="STA association" ssid="rampuss_nomap" ssid_id="WLAN1.0" bssid="00:1a:8c:7f:bc:c4" sta="3c:28:6d:ea:ad:ea" status_code="0"
2023:12:23-08:11:37 A4002469308FE64 awelogger[1375]: id="4101" severity="info" sys="System" sub="WiFi" name="STA connected" ssid="rampuss_nomap" ssid_id="WLAN1.0" bssid="00:1a:8c:7f:bc:c4" sta="3c:28:6d:ea:ad:ea"

You can also see that the archived logs show when this occurs:

Log Archive

Normally my WiFi logs are about 2-4KB compressed. Anything over 10KB is from a day when the AP was choking

Sophos UTM Home user since 2015

Running on Q350G4 Core i5-4200U 8GB

Reply