OK, noe mer kjøtt på beina. Du har nok helt rett - årsaken til feilen ligger mest sannsynlig i mitt trådløse nett. Det som har forvirret meg er at Pow-K modulen rebooter. Men dette er trigget av nettverksproblemene og ikke motsatt.
Var i tilstanden der modulen ikke svarte på ping. I følge aksesspunkte var den aktiv på wifi (inactive time < 1 s):
root@u6-1:~# iw wlan0-1 station get 50:02:91:e0:4a:15
Station 50:02:91:e0:4a:15 (on wlan0-1)
inactive time: 910 ms
rx bytes: 2939834
rx packets: 62674
tx bytes: 1578596
tx packets: 13205
tx retries: 7603
tx failed: 0
rx drop misc: 0
signal: -77 [-77, -83] dBm
signal avg: -76 [-76, -81] dBm
tx bitrate: 54.0 MBit/s
tx duration: 2247072 us
rx bitrate: 6.0 MBit/s
rx duration: 6620293 us
airtime weight: 256
expected throughput: 18.126Mbps
authorized: yes
authenticated: yes
associated: yes
preamble: short
WMM/WME: no
MFP: no
TDLS peer: no
DTIM period: 2
beacon interval:100
short preamble: yes
connected time: 27051 seconds
associated at [boottime]: 1159508.557s
associated at: 1629950047588 ms
current time: 1629977098573 ms
Men IP-messig var det altså dødt. Jeg har sett tilsvarende med et IP-kamera på dette nettet før, så jeg holder en knapp på en AP-relatert bug (halveksperimentell OpenWrt installasjon). Trigget en reconnect, og det virket tilsynelatende som det skulle:
root@u6-1:~# iw wlan0-1 station del 50:02:91:e0:4a:15
root@u6-1:~# iw wlan0-1 station get 50:02:91:e0:4a:15
Station 50:02:91:e0:4a:15 (on wlan0-1)
inactive time: 220 ms
rx bytes: 11664
rx packets: 179
tx bytes: 2322
tx packets: 21
tx retries: 11
tx failed: 0
rx drop misc: 0
signal: -76 [-76, -82] dBm
signal avg: -76 [-76, -82] dBm
tx bitrate: 48.0 MBit/s
tx duration: 13376 us
rx bitrate: 6.0 MBit/s
rx duration: 46173 us
airtime weight: 256
expected throughput: 16.113Mbps
authorized: yes
authenticated: yes
associated: yes
preamble: short
WMM/WME: no
MFP: no
TDLS peer: no
DTIM period: 2
beacon interval:100
short preamble: yes
connected time: 80 seconds
associated at [boottime]: 1186733.477s
associated at: 1629977272509 ms
current time: 1629977352458 ms
Men så skjer det noe. Loggen fra DHCP-serveren viser 3 fulle runder med DISCOVER++:
Aug 26 13:27:52 idefix dhcpd[860] DHCPDISCOVER from 50:02:91:e0:4a:15 (ams-4a15) via eth0.15
Aug 26 13:27:52 idefix dhcpd[860] DHCPOFFER on 192.168.15.9 to 50:02:91:e0:4a:15 (ams-4a15) via eth0.15
Aug 26 13:27:52 idefix dhcpd[860] DHCPREQUEST for 192.168.15.9 (192.168.15.1) from 50:02:91:e0:4a:15 (ams-4a15) via eth0.15
Aug 26 13:27:52 idefix dhcpd[860] DHCPACK on 192.168.15.9 to 50:02:91:e0:4a:15 (ams-4a15) via eth0.15
Aug 26 13:29:58 idefix dhcpd[860] DHCPDISCOVER from 50:02:91:e0:4a:15 (ams-4a15) via eth0.15
Aug 26 13:29:58 idefix dhcpd[860] DHCPOFFER on 192.168.15.9 to 50:02:91:e0:4a:15 (ams-4a15) via eth0.15
Aug 26 13:29:58 idefix dhcpd[860] DHCPREQUEST for 192.168.15.9 (192.168.15.1) from 50:02:91:e0:4a:15 (ams-4a15) via eth0.15
Aug 26 13:29:58 idefix dhcpd[860] DHCPACK on 192.168.15.9 to 50:02:91:e0:4a:15 (ESP-E04A15) via eth0.15
Aug 26 13:30:11 idefix dhcpd[860] DHCPDISCOVER from 50:02:91:e0:4a:15 (ESP-E04A15) via eth0.15
Aug 26 13:30:11 idefix dhcpd[860] DHCPOFFER on 192.168.15.9 to 50:02:91:e0:4a:15 (ESP-E04A15) via eth0.15
Aug 26 13:30:11 idefix dhcpd[860] DHCPREQUEST for 192.168.15.9 (192.168.15.1) from 50:02:91:e0:4a:15 (ESP-E04A15) via eth0.15
Aug 26 13:30:11 idefix dhcpd[860] DHCPACK on 192.168.15.9 to 50:02:91:e0:4a:15 (ams-4a15) via eth0.15
Loggen fra aksesspunktet matcher:
Aug 26 13:27:29 u6-1.mork.no hostapd wlan0-1: AP-STA-DISCONNECTED 50:02:91:e0:4a:15
Aug 26 13:27:29 u6-1.mork.no hostapd wlan0-1: STA 50:02:91:e0:4a:15 IEEE 802.11: disassociated due to inactivity
Aug 26 13:27:30 u6-1.mork.no hostapd wlan0-1: STA 50:02:91:e0:4a:15 IEEE 802.11: deauthenticated due to inactivity (timer DEAUTH/REMOVE)
Aug 26 13:27:52 u6-1.mork.no hostapd wlan0-1: STA 50:02:91:e0:4a:15 IEEE 802.11: authenticated
Aug 26 13:27:52 u6-1.mork.no hostapd wlan0-1: STA 50:02:91:e0:4a:15 IEEE 802.11: associated (aid 2)
Aug 26 13:27:52 u6-1.mork.no hostapd wlan0-1: AP-STA-CONNECTED 50:02:91:e0:4a:15
Aug 26 13:27:52 u6-1.mork.no hostapd wlan0-1: STA 50:02:91:e0:4a:15 WPA: pairwise key handshake completed (RSN)
Aug 26 13:27:52 u6-1.mork.no hostapd wlan0-1: EAPOL-4WAY-HS-COMPLETED 50:02:91:e0:4a:15
Aug 26 13:29:58 u6-1.mork.no hostapd wlan0-1: AP-STA-DISCONNECTED 50:02:91:e0:4a:15
Aug 26 13:29:58 u6-1.mork.no hostapd wlan0-1: STA 50:02:91:e0:4a:15 IEEE 802.11: authenticated
Aug 26 13:29:58 u6-1.mork.no hostapd wlan0-1: STA 50:02:91:e0:4a:15 IEEE 802.11: associated (aid 2)
Aug 26 13:29:58 u6-1.mork.no hostapd wlan0-1: AP-STA-CONNECTED 50:02:91:e0:4a:15
Aug 26 13:29:58 u6-1.mork.no hostapd wlan0-1: STA 50:02:91:e0:4a:15 WPA: pairwise key handshake completed (RSN)
Aug 26 13:29:58 u6-1.mork.no hostapd wlan0-1: EAPOL-4WAY-HS-COMPLETED 50:02:91:e0:4a:15
Aug 26 13:29:58 u6-1.mork.no hostapd wlan0-1: AP-STA-DISCONNECTED 50:02:91:e0:4a:15
Aug 26 13:29:58 u6-1.mork.no hostapd wlan0-1: STA 50:02:91:e0:4a:15 IEEE 802.11: disassociated
Aug 26 13:29:58 u6-1.mork.no hostapd wlan0-1: STA 50:02:91:e0:4a:15 IEEE 802.11: disassociated
Aug 26 13:29:58 u6-1.mork.no hostapd wlan0-1: STA 50:02:91:e0:4a:15 IEEE 802.11: disassociated
Aug 26 13:29:58 u6-1.mork.no hostapd wlan0-1: STA 50:02:91:e0:4a:15 IEEE 802.11: disassociated
Aug 26 13:29:58 u6-1.mork.no hostapd wlan0-1: STA 50:02:91:e0:4a:15 IEEE 802.11: disassociated
Aug 26 13:29:59 u6-1.mork.no hostapd wlan0-1: STA 50:02:91:e0:4a:15 IEEE 802.11: deauthenticated due to inactivity (timer DEAUTH/REMOVE)
Aug 26 13:30:11 u6-1.mork.no hostapd wlan0-1: STA 50:02:91:e0:4a:15 IEEE 802.11: authenticated
Aug 26 13:30:11 u6-1.mork.no hostapd wlan0-1: STA 50:02:91:e0:4a:15 IEEE 802.11: associated (aid 2)
Aug 26 13:30:11 u6-1.mork.no hostapd wlan0-1: AP-STA-CONNECTED 50:02:91:e0:4a:15
Aug 26 13:30:11 u6-1.mork.no hostapd wlan0-1: STA 50:02:91:e0:4a:15 WPA: pairwise key handshake completed (RSN)
Aug 26 13:30:11 u6-1.mork.no hostapd wlan0-1: EAPOL-4WAY-HS-COMPLETED 50:02:91:e0:4a:15
Og jeg ser også at vi har fått en ny "associated at" tid:
root@u6-1:~# iw wlan0-1 station get 50:02:91:e0:4a:15
Station 50:02:91:e0:4a:15 (on wlan0-1)
inactive time: 0 ms
rx bytes: 1996
rx packets: 16
tx bytes: 1656
tx packets: 12
tx retries: 0
tx failed: 0
rx drop misc: 0
signal: -77 [-77, -81] dBm
signal avg: -75 [-75, -80] dBm
tx bitrate: 6.0 MBit/s
tx duration: 11968 us
rx bitrate: 1.0 MBit/s
rx duration: 18172 us
airtime weight: 256
expected throughput: 4.394Mbps
authorized: yes
authenticated: yes
associated: yes
preamble: short
WMM/WME: no
MFP: no
TDLS peer: no
DTIM period: 2
beacon interval:100
short preamble: yes
connected time: 0 seconds
associated at [boottime]: 1186872.079s
associated at: 1629977411112 ms
current time: 1629977411318 ms
Årsaken til alt dette igjen, er at Pow-K har rebootet. Den viser nå en oppetid på noen sekunder. Så det ser ut til at den ikke takler denne WiFi-reconnect situasjonen. Noe som kræsjer på seg ved andregangs initalisering av WiFi, kanskje? Muligens MQTT-klienten?
Burde være overkommelig å teste den teorien med serieport-debugging slik at man kan se hva som skjer. Setter det på TODO-lista. Ville bare si fra i tilfelle andre har lyst til å teste ut teorien.