Archer C7 2.4 GHz wireless dies in 24~48 hours

csantz · 2021-05-27T12:10:49.550Z

@anon2180415 I'm using CT HTT firmware, opensource version, with non CT firmware I did not experienced any problems.

anon2180415 · 2021-05-27T12:22:55.207Z

Dito, non-ct firmware on my 5 archers takes a "long time" until problems like bad wifi throughput / high pings / sudden disconnects and reconnects start to occur. Works well for me most of the time, but I'm still seeking to find the root cause of an error if it pops up.

I've now repeated my above mentioned tests and changed the distance from my mobile phones generating lots of 2.4 GHz WiFi load from 5 meters to 20 meters. I re-ran "iw event -f -t " and converted the unix timestamps to local time stamps to analyze the frequency of event 60.

I've read previous post of other topics on the Archer C7's WiFi problems telling that the distance AP <=> mobile device increase may also cause more problematic connection quality to appear.

image726×529 39.3 KB

anon2180415 · 2021-05-27T12:44:35.409Z

Currently trying the above workaround "if it helps against WiFi problems". I have no proof about it so want to try. Whenever event 60 (frame_tx_status) occurs on 2.4 GHz "wlan1", a scan is triggered "as workaround".

iw event -t -f | grep "wlan1.*: unknown event 60" | while read line; do echo $(date +%Y-%m-%d_%H-%M-%S): scan...; iw dev wlan1 scan trigger freq 2447 flush; done;

output:

2021-41-27_14-05-52: scan...
2021-44-27_14-05-53: scan...
2021-44-27_14-05-53: scan...
command failed: Resource busy (-16)
2021-44-27_14-05-53: scan...
command failed: Resource busy (-16)
2021-44-27_14-05-53: scan...
command failed: Resource busy (-16)
2021-44-27_14-05-53: scan...
command failed: Resource busy (-16)
2021-44-27_14-05-53: scan...
2021-44-27_14-05-53: scan...
command failed: Resource busy (-16)
2021-44-27_14-05-53: scan...
command failed: Resource busy (-16)
2021-44-27_14-05-53: scan...
command failed: Resource busy (-16)
2021-44-27_14-05-53: scan...
command failed: Resource busy (-16)
2021-44-27_14-05-53: scan...
2021-44-27_14-05-53: scan...
command failed: Resource busy (-16)
2021-44-27_14-05-53: scan...
command failed: Resource busy (-16)
2021-44-27_14-05-53: scan...
command failed: Resource busy (-16)
2021-44-27_14-05-53: scan...
command failed: Resource busy (-16)
2021-44-27_14-05-53: scan...
2021-44-27_14-05-53: scan...
command failed: Resource busy (-16)
2021-44-27_14-05-53: scan...
command failed: Resource busy (-16)
2021-44-27_14-05-53: scan...
command failed: Resource busy (-16)

There seems to be a high frequency of those event 60 log lines per second shortly after a scan was triggered. It's "good" that the scans do not queue up but instead one scan is finished before another one could be launched.

@sammo did a good guess: The frequency 30 sec. was "the average" delay between the event 60 log lines in my test setup.

My 2.4 GHz phone (without running anything) sometimes spikes up in ping around 600 ms. That's exactly when event 60 comes in and the "wifi scan" is triggered. It seems to "lower my ping immediately" when the scan takes place on the 2.4 GHz radio.

image1579×578 68.9 KB

Notes for me:

https://insidelinuxdev.net/article/a0aby8.html
iw event 70 - unprot_deauthenticate
had this once in my wlan1 2.4 GHz logs, explanation: https://praneethwifi.in/2020/03/07/protected-management-frames-in-wpa2-802-11w-wpa3-owe/

Does the 2.4 GHz drop maybe also relate somehow with management frame protection which I set to "optional"?

anon2180415 · 2021-05-27T13:32:10.567Z

With scans triggered by "event 60" I've got about 6 times faster down/up speed and pings never going up higher than 500 ms in 20 meters distance from the AP.

Without scans triggered by "event 60" I've got pings between 100 ms and 1000 ms plus lower down/up speed in 20 meters distance from the AP.

I absolutely have no clue why the "iw scan trigger " workaround does its job, but somehow feels better with it.

iw event -t -f | grep "wlan1.*: unknown event 60" | while read line; do echo $(date +%Y-%m-%d_%H-%M-%S): scan...; iw dev wlan1 scan trigger freq 2447 flush; done;

sammo · 2021-05-27T13:39:56.852Z

@anon2180415 much appreciated for your investigation, is this the workaround?

sammo · 2021-05-27T15:20:54.169Z

You are hardcoding wlan1 after you got the varible in RADIO_ATH9K

anon2180415:

	RADIO_ATH9K="$(iw dev|grep "Interface\|channel\|type"|grep -B 2 'channel.*24..'|grep -m 1 -B 1 'AP'|awk '/Interface/ {print $2}')"
	logAdd "[INFO] BEGIN iw_event_scan_trigger ON interface [${RADIO_ATH9K}]"
	iw event -t -f | while read line; do
		if $(echo -n "${line}" | grep -q "wlan1.*: unknown event 60"); then
			# logAdd "$(date +%Y-%m-%d_%H-%M-%S): Scan ..."
			iw dev wlan1 scan trigger freq 2447 flush >/dev/null 2>&1
		fi
	done

anon2180415 · 2021-05-27T18:28:03.893Z

... thanks! My mistake, updated the script.

sammo · 2021-05-27T20:38:50.787Z

Uwe,

Not nitpicking, if you have guest AP on 2.4Ghz also

[ $(cat /sys/kernel/debug/ieee80211/phy1/netdev:*/num_mcast_sta|awk '{ SUM += $1} END { print SUM }') -eq 0 ] && { do stuff }

anon2180415 · 2021-05-28T09:19:20.393Z

anon2180415:

iw dev|grep "Interface\|channel\|type"|grep -B 2 'channel.*24..'|grep -B 1 'AP'|tail -n 2|grep Interface|awk '{print $2}'

Fixed radio detection in script. Before, it said "wlan1-3", now it says "wlan1".

Script updated - see Archer C7 2.4 GHz wireless dies in 24~48 hours - #199

Catfriend1 · 2021-05-28T15:06:20.634Z

Tried the above watchdog script and my wifi works fine under simulated iperf load. thank you for all the work on this.

sammo · 2021-05-28T16:01:45.721Z

Anybody tested STA/AP as mine is a travel router ......
Does it need the scan or something else. I'm see a different problem with STA/AP on 2.4Ghz

Fri May 28 12:15:23 2021 daemon.notice wpa_supplicant[1402]: wlan9: CTRL-EVENT-BEACON-LOSS
then it disconnect from the upstream AP

sammo · 2021-05-29T08:59:59.797Z

Just a thought, if you have 30 clients connected and they all rise the event at the same time, you will have spawn 30 scans which could overwhelm the CPU. Need to prevent multi spawn

Catfriend1 · 2021-05-29T10:32:34.244Z

I tested this, when a scan is already triggered but not completed when the next scan commands fires a message is thrown from iw like "device busy - code XX".

What would be more smart: if the last scan was less than 10 seconds ago , sleep 10 seconds and then trigger a new scan. This would lower scan count in total and guarantee that every iw event 60 gets a scan afterwards. Not sure how to do it in script to cancel "iw event 60 pending buffer" once a scan just launched - or the described mechanism would queue up scans probably faster then the 10s + scan delay passes by.

sammo · 2021-05-29T10:44:22.924Z

if mkdir /tmp/scan.txt; then
       iw scan......
       (sleep 30 && rm -rf /tmp/scan.txt)&
fi

Quick and nasty

sammo · 2021-05-29T17:24:29.605Z

My bad , I just move the goal post and replace scan with mkdir. Still external command call. Each event has a epoch time in the first field. Using built-in shell for checks

dt=0
iw event -f -t| while read line; do

if [ ${line%%.*} -gt $dt ] ; then
      scan
      dt=$(($(date +%s)+10))
fi

done

anon2180415 · 2021-06-18T09:20:43.404Z

Now creating a watchdog shell script.

/etc/rc.local

# Put your custom commands here that should be executed once
# the system init finished. By default this file does nothing.

/bin/bash /root/ath9k-watchdog.sh start &

exit 0

/root/ath9k-watchdog.sh

#/bin/bash
#
# Purpose:
# 	Watch ath9k 2.4 GHz wadio event 60 and if the event occurs, trigger a WiFi scan as a workaround to avoid issues
# 	slowly creeping up like higher WiFi latency or unexpected WiFi client disconnects.
#
# Installation:
#	bash "/root/ath9k-watchdog.sh" install
#
# Command line:
# 	bash "/root/ath9k-watchdog.sh" livelog
# 	bash "/root/ath9k-watchdog.sh" start &
# 	bash "/root/ath9k-watchdog.sh" stop
#
# For testing purposes only:
# 	bash "/root/ath9k-watchdog.sh" start
#
# Prerequisites:
#	BASH
#
# Script Configuration.
PATH=/usr/bin:/usr/sbin:/sbin:/bin
SCRIPT_FULLFN="$(basename -- "${0}")"
SCRIPT_NAME="${SCRIPT_FULLFN%.*}"
LOGFILE="/tmp/${SCRIPT_NAME}.log"
LOG_MAX_LINES="1000"
#
#
# -----------------------------------------------------
# -------------- START OF FUNCTION BLOCK --------------
# -----------------------------------------------------
logAdd ()
{
	TMP_DATETIME="$(date '+%Y-%m-%d [%H-%M-%S]')"
	TMP_LOGSTREAM="$(tail -n ${LOG_MAX_LINES} ${LOGFILE} 2>/dev/null)"
	echo "${TMP_LOGSTREAM}" > "$LOGFILE"
	echo "${TMP_DATETIME} $*" | tee -a "${LOGFILE}"
	return
}


serviceMain ()
{
	#
	# Usage:		serviceMain
	# Called By:	MAIN
	#
	logAdd "[INFO] === SERVICE START ==="
	#
	logAdd "[INFO] Waiting to discover 2.4 GHz radio interface ..."
	while (true); do
		RADIO_ATH9K="$(iw dev|grep "Interface\|channel\|type"|grep -B 2 'channel.*24..'|grep -B 1 'AP'|tail -n 2|grep Interface|awk '{print $2}')"
		if [ ! -z "${RADIO_ATH9K}" ]; then
			break
		fi
		sleep 10
	done
	#
	logAdd "[INFO] Setup iw_event_scan_trigger on interface [${RADIO_ATH9K}]"
	#
	dt=0
	iw event -t -f | while read line; do
		if $(echo -n "${line}" | grep -q "${RADIO_ATH9K}.*: unknown event 60"); then
			#
			# Check if the last scan was more than 10 seconds ago.
			if [ ${line%%.*} -gt ${dt} ] ; then
				echo "$(date +%Y-%m-%d_%H-%M-%S): ${dt} ${RADIO_ATH9K} scan ..."
				iw dev ${RADIO_ATH9K} scan trigger freq 2447 flush >/dev/null 2>&1
				dt=$(($(date +%s)+10))
			fi
		fi
	done
	#
	return 0
}
# ---------------------------------------------------
# -------------- END OF FUNCTION BLOCK --------------
# ---------------------------------------------------
#
# Check shell
if [ ! -n "${BASH_VERSION}" ]; then
	logAdd "[ERROR] Wrong shell environment, please run with bash."
	exit 99
fi
#
trap "" SIGHUP
trap "trap - SIGTERM && kill -- -$$" SIGINT SIGTERM EXIT
#
if [ "${1}" = "install" ]; then
	if ( grep -q "$(which bash) $(readlink -f "${0}") start &" "/etc/rc.local"); then
		echo "[INFO] Script already present in startup."
		exit 0
	fi
	sed -i "\~^exit 0~i $(which bash) $(readlink -f "${0}") start &\n" "/etc/rc.local"
	echo "[INFO] Script successfully added to startup."
	exit 0
elif [ "${1}" = "livelog" ]; then
	tail -f "${LOGFILE}"
	exit 0
elif [ "${1}" = "start" ]; then
	serviceMain &
	#
	# Wait for kill -INT.
	wait
	exit 0
elif [ "${1}" = "stop" ]; then
	ps w | grep -v grep | grep "$(basename -- $(which bash)) .*$(basename -- ${0}) start" | sed 's/ \+/|/g' | sed 's/^|//' | cut -d '|' -f 1 | grep -v "^$$" | while read pidhandle; do
		echo "[INFO] Terminating old service instance [${pidhandle}] ..."
		kill -INT "${pidhandle}" 2>/dev/null
		kill "${pidhandle}" 2>/dev/null
	done
	#
	# Check if parts of the service are still running.
	if [ "$(ps w | grep -v grep | grep "$(basename -- $(which bash)) .*$(basename -- ${0}) start" | sed 's/ \+/|/g' | sed 's/^|//' | cut -d '|' -f 1 | grep -v "^$$" | wc -l)" -gt 0 ]; then
		logAdd "[ERROR] === SERVICE FAILED TO STOP ==="
		ps w | grep "iw event\|${SCRIPT_NAME}" | grep -v grep
		exit 99
	fi
	#
	killall iw 2>/dev/null
	#
	logAdd "[INFO] === SERVICE STOPPED ==="
	exit 0
fi
#
logAdd "[ERROR] Parameter #1 missing."
logAdd "[INFO] Usage: bash ${SCRIPT_FULLFN} {install|livelog|start|stop}"
exit 99

To see if the watchdog triggers the scans appropriately, put "iw event -t -f " into the SSH shell running in parallel. After "unknown event 60" lines there should be "unknown event 33/34" lines afterwards if the scan was triggered by the watchdog script.

Log should look like this:

1622199174.822862: wlan1-2 (phy #1): unknown event 60
1622199174.823196: wlan1-2 (phy #1): unknown event 60
1622199174.866459: wlan1 (phy #1): unknown event 33
1622199174.941817: wlan1 (phy #1): unknown event 34

Catfriend1 · 2021-06-18T09:22:56.758Z

@anon2180415 Thanks for contacting me to update my original ath10k-ct-watchdog script and put both to my openwrt "useful scripts" repo for the TP-Link Archer C7v2|5.

@sammo Perfect, I've intregrated your snippet into the script and it works well, now throttling scans if the last scan was less than 10 seconds ago.

We've now agreed to put the recent version of the script here:

https://github.com/Catfriend1/openwrt-presence/tree/master/scripts/ath10k-ct-watchdog
https://github.com/Catfriend1/openwrt-presence/blob/master/scripts/ath9k-watchdog/ath9k-watchdog.sh

sammo · 2021-06-18T09:39:10.561Z

I would swap these 2 lines round. echo,grep mean more external command calls and using up resources

	if $(echo -n "${line}" | grep -q "${RADIO_ATH9K}.*: unknown event 60"); then
			#
			# Check if the last scan was more than 10 seconds ago.
			if [ ${line%%.*} -gt ${dt} ] ; then

supperchym · 2021-06-24T19:16:51.603Z

i found telegram script in your github, what is that ?

Catfriend1 · 2021-06-24T20:37:48.427Z

it's a little "library" easy to integrate into your own bash scripts and to send/edit telegram notifications via a telegram bot to your phone.

I use it for different things, lately to notify myself of unexpected router reboots.