Wi-fi connection drops, messages not acknowledged

Hello,
Just noticed that the Wi-fi connection drops after a while (1~2 hours) and I get no ACK messages back from the node. The CLI through LAN drops as well, no ping reply on the IP address. After a while, it looks like it reboots itself and everything is back to normal.

My config:
2 x Tbeam boards, one has the Wi-fi client mode activated and the other one is connected to my phone (bluetooth). Firmware on both boards is “firmware-tbeam-1.3.46.d4ea956.bin”

Seems like the device is not always rebooting itself. It is however responsive locally (Oled screen and button) but wireless never reconnects. Also, it doesn’t seem to ack any packets in the radio network (watched that on the radio spectrum as well).
I now have disabled the wi-fi client and will check it periodically just to see if the the problem is gone.

The fact that we can now access the nodes using the phone-app trough the IP network is really a great thing in my opinion! The App is really handy compared to the web interface.
Having my fixed node always powered in the comms. rack and always connected to the external antenna gives me the possibility of accessing it through VPN from wherever I go. So Wi-fi/IP functionality is pretty important to me.

Regards,
Mihai

Can you post the results of meshtastic --info here so that we can see some settings to try to reproduce? Make sure not to accidentally post your wifi password :sweat_smile:

Thanks for the tip about the password. I also masked the exact GPS data, just to prevent a rocket strike :slight_smile: :rofl:

Here is the output:

~$ meshtastic  --info --host 192.168.1.134
Connected to radio

Owner: Dezmir (Dzm)
My info: { "myNodeNum": 4064721212, "hasGps": true, "maxChannels": 8, "firmwareVersion": "1.3.46.d4ea956-d", "rebootCount": 42, "bitrate": 17.08847, "messageTimeoutMsec": 300000, "minAppVersion": 20300, "hasWifi": true, "channelUtilization": 28.453333, "airUtilTx": 2.7455 }
Nodes in mesh:  {'num': 4064721212, 'user': {'id': '!f246b93c', 'longName': 'Dezmir', 'shortName': 'Dzm', 'macaddr': '08:3a:f2:46:b9:3c', 'hwModel': 'TBEAM', 'isLicensed': True}, 'position': {'latitudeI': XXX, 'longitudeI': XXX, 'altitude': 425, 'seqNumber': 10, 'latitude': 46.XXX, 'longitude': 23.XXX}, 'snr': 8.75, 'lastHeard': 1666613687, 'deviceMetrics': {'batteryLevel': 98, 'voltage': 4.127, 'channelUtilization': 13.799999, 'airUtilTx': 2.4016945}}  {'num': 4064639896, 'user': {'id': '!f2457b98', 'longName': 'YO5OMT', 'shortName': 'Y5M', 'macaddr': '08:3a:f2:45:7b:98', 'hwModel': 'TBEAM', 'isLicensed': True}, 'position': {'latitudeI': XXX, 'longitudeI': XXX, 'altitude': 379, 'time': 1666612209, 'latitude': 46.XXX, 'longitude': 23.XXX}, 'snr': 8.25, 'lastHeard': 1666613269, 'deviceMetrics': {'batteryLevel': 10, 'voltage': 3.615, 'airUtilTx': 5.5794444}}  {'num': 4064716044, 'user': {'id': '!f246a50c', 'longName': 'Campului', 'shortName': 'Cmp', 'macaddr': '08:3a:f2:46:a5:0c', 'hwModel': 'TBEAM'}, 'position': {'latitudeI': XXX, 'longitudeI': XXX, 'altitude': 364, 'time': 1666612505, 'latitude': 46.XXX, 'longitude': 23.XXX}, 'snr': -11.75, 'lastHeard': 1666612521, 'deviceMetrics': {'batteryLevel': 96, 'voltage': 4.117, 'airUtilTx': 5.489278}}  {'num': 4064686520, 'user': {'id': '!f24631b8', 'longName': 'Buscat', 'shortName': 'Bsc', 'macaddr': '08:3a:f2:46:31:b8', 'hwModel': 'TBEAM', 'isLicensed': True}, 'position': {'latitudeI': XXX 'longitudeI': XXX, 'altitude': 468, 'time': 1666612831, 'latitude': 46.XXX, 'longitude': 23.XXX}, 'snr': 12.25, 'lastHeard': 1666613540, 'deviceMetrics': {'batteryLevel': 67, 'voltage': 3.888, 'channelUtilization': 13.799999, 'airUtilTx': 3.257361}}

Preferences: { "device": { "serialEnabled": true }, "position": { "positionBroadcastSecs": 300, "positionBroadcastSmartEnabled": true, "fixedPosition": true, "gpsEnabled": true, "gpsUpdateInterval": 120, "gpsAttemptTime": 900, "positionFlags": 3 }, "power": { "waitBluetoothSecs": 60, "meshSdsTimeoutSecs": 4294967295, "sdsSecs": 4294967295, "lsSecs": 300, "minWakeSecs": 10 }, "network": { "wifiEnabled": true, "wifiSsid": "XXX", "wifiPsk": "XXX", "ntpServer": "0.pool.ntp.org" }, "display": { "screenOnSecs": 600 }, "lora": { "usePreset": true, "modemPreset": "LONG_SLOW", "region": "EU_433", "hopLimit": 3, "txEnabled": true, "txPower": 12 }, "bluetooth": { "enabled": true, "fixedPin": 123456 } }

Module preferences: { "mqtt": {}, "serial": {}, "externalNotification": {}, "rangeTest": {}, "telemetry": { "deviceUpdateInterval": 900, "environmentUpdateInterval": 900 }, "cannedMessage": {} }

Channels:
  PRIMARY psk=unencrypted { "psk": "AA==", "name": "HAMradio-2" }

I’ve also started the wi-fi client on a second node with a fresh firmware update. Let’s see what happens with them…

Later edit: By the way, why is it that only about 50% of CLI commands sent out through IP/LAN are getting a good response? The other ones just end up in a bunch of python error messages…
It’s not like I have packet loss on the network (checked that by pinging the node with large packets).
I’m using:

~$ meshtastic --version
1.3.40

Hi,
Here are some updates:
Both nodes connected through wi-fi (client mode) dropped connection after approx. 2 hours. The display is responsive, the wi-fi screen says “connected”, even measure the RSSI in real-time.
There is no response on the IP however.

I looked on the debug output immediately after (connected the USB) and restarted the access point just to see the output:

[11678423][D][WiFiGeneric.cpp:929] _eventCallback(): Arduino Event: 5 - STA_DISCONNECTED
[11678424][W][WiFiGeneric.cpp:950] _eventCallback(): Reason: 200 - BEACON_TIMEOUT
[11678428][D][WiFiGeneric.cpp:966] _eventCallback(): WiFi Reconnect Running
14:56:21 11678 ************ [WiFi-event] event: 5 ************
14:56:21 11678 Disconnected from WiFi access point

WiFi lost connection. Reason: 200
[11680866][D][WiFiGeneric.cpp:929] _eventCallback(): Arduino Event: 5 - STA_DISCONNECTED
[11680867][W][WiFiGeneric.cpp:950] _eventCallback(): Reason: 201 - NO_AP_FOUND
[11680870][D][WiFiGeneric.cpp:975] _eventCallback(): WiFi AutoReconnect Running
14:56:24 11680 ************ [WiFi-event] event: 5 ************
14:56:24 11680 Disconnected from WiFi access point

WiFi lost connection. Reason: 201
[11683295][D][WiFiGeneric.cpp:929] _eventCallback(): Arduino Event: 5 - STA_DISCONNECTED
[11683295][W][WiFiGeneric.cpp:950] _eventCallback(): Reason: 201 - NO_AP_FOUND
[11683299][D][WiFiGeneric.cpp:975] _eventCallback(): WiFi AutoReconnect Running
14:56:26 11683 [Button] ************ [WiFi-event] event: 5 ************
14:56:26 11683 [Button] Disconnected from WiFi access point

WiFi lost connection. Reason: 201
[11685723][D][WiFiGeneric.cpp:929] _eventCallback(): Arduino Event: 5 - STA_DISCONNECTED
[11685724][W][WiFiGeneric.cpp:950] _eventCallback(): Reason: 201 - NO_AP_FOUND
[11685727][D][WiFiGeneric.cpp:975] _eventCallback(): WiFi AutoReconnect Running
14:56:29 11685 ************ [WiFi-event] event: 5 ************
14:56:29 11685 Disconnected from WiFi access point

WiFi lost connection. Reason: 201
14:56:30 11687 [Power] Battery: usbPower=1, isCharging=1, batMv=4112, batPct=96
[11688152][D][WiFiGeneric.cpp:929] _eventCallback(): Arduino Event: 5 - STA_DISCONNECTED
[11688153][W][WiFiGeneric.cpp:950] _eventCallback(): Reason: 201 - NO_AP_FOUND
[11688156][D][WiFiGeneric.cpp:975] _eventCallback(): WiFi AutoReconnect Running
14:56:31 11688 ************ [WiFi-event] event: 5 ************
14:56:31 11688 Disconnected from WiFi access point

WiFi lost connection. Reason: 201
[11690581][D][WiFiGeneric.cpp:929] _eventCallback(): Arduino Event: 5 - STA_DISCONNECTED
[11690581][W][WiFiGeneric.cpp:950] _eventCallback(): Reason: 201 - NO_AP_FOUND
[11690585][D][WiFiGeneric.cpp:975] _eventCallback(): WiFi AutoReconnect Running
14:56:33 11690 ************ [WiFi-event] event: 5 ************
14:56:33 11690 Disconnected from WiFi access point

WiFi lost connection. Reason: 201
[11693009][D][WiFiGeneric.cpp:929] _eventCallback(): Arduino Event: 5 - STA_DISCONNECTED
[11693010][W][WiFiGeneric.cpp:950] _eventCallback(): Reason: 201 - NO_AP_FOUND
[11693013][D][WiFiGeneric.cpp:975] _eventCallback(): WiFi AutoReconnect Running
14:56:36 11693 [WebServerThread] ************ [WiFi-event] event: 5 ************
14:56:36 11693 [WebServerThread] Disconnected from WiFi access point

WiFi lost connection. Reason: 201
[11694062][D][WiFiGeneric.cpp:929] _eventCallback(): Arduino Event: 5 - STA_DISCONNECTED
[11694063][W][WiFiGeneric.cpp:950] _eventCallback(): Reason: 2 - AUTH_EXPIRE
[11694066][D][WiFiGeneric.cpp:975] _eventCallback(): WiFi AutoReconnect Running
14:56:37 11694 ************ [WiFi-event] event: 5 ************
14:56:37 11694 Disconnected from WiFi access point

WiFi lost connection. Reason: 2
[11694441][D][WiFiGeneric.cpp:929] _eventCallback(): Arduino Event: 4 - STA_CONNECTED
14:56:37 11694 ************ [WiFi-event] event: 4 ************
14:56:37 11694 Connected to access point
[11704075][D][WiFiGeneric.cpp:929] _eventCallback(): Arduino Event: 5 - STA_DISCONNECTED
[11704075][W][WiFiGeneric.cpp:950] _eventCallback(): Reason: 2 - AUTH_EXPIRE
[11704079][D][WiFiGeneric.cpp:975] _eventCallback(): WiFi AutoReconnect Running
14:56:47 11704 ************ [WiFi-event] event: 5 ************
14:56:47 11704 Disconnected from WiFi access point

WiFi lost connection. Reason: 2
[11704152][D][WiFiGeneric.cpp:929] _eventCallback(): Arduino Event: 4 - STA_CONNECTED
14:56:47 11704 [WebServerThread] ************ [WiFi-event] event: 4 ************
14:56:47 11704 Connected to access point

[11798424][D][WiFiGeneric.cpp:929] _eventCallback(): Arduino Event: 9 - STA_LOST_IP
14:58:21 11798 ************ [WiFi-event] event: 9 ************

I also did a test in a working situation (after reset) and the difference is that it gets an IP after access point is restarted…:

[745907][D][WiFiGeneric.cpp:929] _eventCallback(): Arduino Event: 5 - STA_DISCONNECTED
[745907][W][WiFiGeneric.cpp:950] _eventCallback(): Reason: 200 - BEACON_TIMEOUT
[745911][D][WiFiGeneric.cpp:975] _eventCallback(): WiFi AutoReconnect Running
15:00:24 745 ************ [WiFi-event] event: 5 ************
15:00:24 745 Disconnected from WiFi access point

WiFi lost connection. Reason: 200
[748339][D][WiFiGeneric.cpp:929] _eventCallback(): Arduino Event: 5 - STA_DISCONNECTED
[748340][W][WiFiGeneric.cpp:950] _eventCallback(): Reason: 201 - NO_AP_FOUND
[748343][D][WiFiGeneric.cpp:975] _eventCallback(): WiFi AutoReconnect Running
15:00:26 748 ************ [WiFi-event] event: 5 ************
15:00:26 748 Disconnected from WiFi access point

WiFi lost connection. Reason: 201
[750767][D][WiFiGeneric.cpp:929] _eventCallback(): Arduino Event: 5 - STA_DISCONNECTED
[750767][W][WiFiGeneric.cpp:950] _eventCallback(): Reason: 201 - NO_AP_FOUND
[750771][D][WiFiGeneric.cpp:975] _eventCallback(): WiFi AutoReconnect Running
15:00:29 750 ************ [WiFi-event] event: 5 ************
15:00:29 750 Disconnected from WiFi access point

WiFi lost connection. Reason: 201
[753194][D][WiFiGeneric.cpp:929] _eventCallback(): Arduino Event: 5 - STA_DISCONNECTED
[753195][W][WiFiGeneric.cpp:950] _eventCallback(): Reason: 201 - NO_AP_FOUND
[753198][D][WiFiGeneric.cpp:975] _eventCallback(): WiFi AutoReconnect Running
15:00:31 753 ************ [WiFi-event] event: 5 ************
15:00:31 753 Disconnected from WiFi access point

WiFi lost connection. Reason: 201
[755622][D][WiFiGeneric.cpp:929] _eventCallback(): Arduino Event: 5 - STA_DISCONNECTED
[755623][W][WiFiGeneric.cpp:950] _eventCallback(): Reason: 201 - NO_AP_FOUND
[755626][D][WiFiGeneric.cpp:975] _eventCallback(): WiFi AutoReconnect Running
15:00:33 755 ************ [WiFi-event] event: 5 ************
15:00:33 755 Disconnected from WiFi access point

WiFi lost connection. Reason: 201
[758050][D][WiFiGeneric.cpp:929] _eventCallback(): Arduino Event: 5 - STA_DISCONNECTED
[758051][W][WiFiGeneric.cpp:950] _eventCallback(): Reason: 201 - NO_AP_FOUND
[758054][D][WiFiGeneric.cpp:975] _eventCallback(): WiFi AutoReconnect Running
15:00:36 758 ************ [WiFi-event] event: 5 ************
15:00:36 758 Disconnected from WiFi access point

WiFi lost connection. Reason: 201
[760478][D][WiFiGeneric.cpp:929] _eventCallback(): Arduino Event: 5 - STA_DISCONNECTED
[760479][W][WiFiGeneric.cpp:950] _eventCallback(): Reason: 201 - NO_AP_FOUND
[760482][D][WiFiGeneric.cpp:975] _eventCallback(): WiFi AutoReconnect Running
15:00:38 760 ************ [WiFi-event] event: 5 ************
15:00:38 760 Disconnected from WiFi access point

WiFi lost connection. Reason: 201
[760608][D][WiFiGeneric.cpp:929] _eventCallback(): Arduino Event: 4 - STA_CONNECTED
15:00:38 760 ************ [WiFi-event] event: 4 ************
15:00:38 760 Connected to access point

[777021][D][WiFiGeneric.cpp:929] _eventCallback(): Arduino Event: 7 - STA_GOT_IP
[777022][D][WiFiGeneric.cpp:991] _eventCallback(): STA IP: 192.168.1.134, MASK: 255.255.255.0, GW: 192.168.1.1
15:00:55 777 ************ [WiFi-event] event: 7 ************
15:00:55 777 Obtained IP address: 192.168.1.134

And here is the last few minutes log before the IP communication stops working. I have to mention that I tried to access the web interface from the PC, while being connected with the phone app at the same time.
Hope this is not too big to post it like this…

17:14:14 8776 [StreamAPI] getFromRadio=STATE_SEND_PACKETS
17:14:14 8776 [StreamAPI] phone downloaded packet (id=0x1d3ac2e0 Fr0x3c To0xff, WantAck0, HopLim3 Ch0x0 Portnum=67 rxtime=1666631654 priority=1)
17:14:14 8776 [StreamAPI] encoding toPhone packet to phone variant=2, 56 bytes
17:14:17 8779 [RadioIf] (bw=125, sf=12, cr=4/8) packet symLen=32 ms, payloadSize=33, time 3153 ms
17:14:17 8779 [RadioIf] Lora RX (id=0x1d3ac2df Fr0x3c To0xff, WantAck0, HopLim2 Ch0x2a encrypted rxSNR=-16 rxRSSI=1.84136)
17:14:17 8779 [RadioIf] AirTime - Packet received : 3153ms
17:14:17 8779 [Router] Rx someone rebroadcasting for us (id=0x1d3ac2df Fr0x3c To0xff, WantAck0, HopLim2 Ch0x2a encrypted rxSNR=-16 rxRSSI=1.84136)
17:14:17 8779 [Router] didn't find pending packet
17:14:17 8779 [Router] Found existing packet record for fr=0xf246b93c,to=0xffffffff,id=0x1d3ac2df
17:14:17 8779 [Router] Found existing packet record for fr=0xf246b93c,to=0xffffffff,id=0x1d3ac2df
17:14:17 8779 [Router] Add packet record (id=0x1d3ac2df Fr0x3c To0xff, WantAck0, HopLim2 Ch0x2a encrypted rxSNR=-16 rxRSSI=1.84136)
17:14:17 8779 [Router] Ignoring incoming msg, because we've already seen it (id=0x1d3ac2df Fr0x3c To0xff, WantAck0, HopLim2 Ch0x2a encrypted rxSNR=-16 rxRSSI=1.84136)
17:14:17 8779 [Router] Incoming message was filtered 0xf246b93c
17:14:23 8785 [Power] Battery: usbPower=1, isCharging=0, batMv=4156, batPct=100
17:14:43 8805 [Power] Battery: usbPower=1, isCharging=0, batMv=4158, batPct=100
17:15:03 8825 [Power] Battery: usbPower=1, isCharging=0, batMv=4156, batPct=100
17:15:14 8835 [DeviceTelemetryModule] (Sending): air_util_tx=3.073778, channel_utilization=5.255000, battery_level=100, voltage=4.156000
17:15:14 8835 [DeviceTelemetryModule] updateTelemetry LOCAL
17:15:14 8836 [DeviceTelemetryModule] Node status update: 2 online, 4 total
17:15:14 8836 [DeviceTelemetryModule] Sending packet to phone
17:15:14 8836 Telling client we have new packets 193
17:15:14 8836 [StreamAPI] getFromRadio=STATE_SEND_PACKETS
17:15:14 8836 [StreamAPI] phone downloaded packet (id=0x1d3ac2e1 Fr0x3c To0xff, WantAck0, HopLim3 Ch0x0 Portnum=67 rxtime=1666631714 priority=1)
17:15:14 8836 [StreamAPI] encoding toPhone packet to phone variant=2, 56 bytes
17:15:23 8845 [Power] Battery: usbPower=1, isCharging=0, batMv=4156, batPct=100
17:15:43 8865 [Power] Battery: usbPower=1, isCharging=0, batMv=4156, batPct=100
17:16:03 8885 [Power] Battery: usbPower=1, isCharging=0, batMv=4156, batPct=100
17:16:14 8896 [DeviceTelemetryModule] (Sending): air_util_tx=3.073778, channel_utilization=0.000000, battery_level=100, voltage=4.156000
17:16:14 8896 [DeviceTelemetryModule] updateTelemetry LOCAL
17:16:14 8896 [DeviceTelemetryModule] Node status update: 2 online, 4 total
17:16:14 8896 [DeviceTelemetryModule] Sending packet to phone
17:16:14 8896 Telling client we have new packets 194
17:16:14 8896 [StreamAPI] getFromRadio=STATE_SEND_PACKETS
17:16:14 8896 [StreamAPI] phone downloaded packet (id=0x1d3ac2e2 Fr0x3c To0xff, WantAck0, HopLim3 Ch0x0 Portnum=67 rxtime=1666631774 priority=1)
17:16:14 8896 [StreamAPI] encoding toPhone packet to phone variant=2, 51 bytes
17:16:23 8905 [Power] Battery: usbPower=1, isCharging=0, batMv=4156, batPct=100
17:16:43 8925 [Power] Battery: usbPower=1, isCharging=0, batMv=4156, batPct=100
17:17:03 8945 [Power] Battery: usbPower=1, isCharging=0, batMv=4156, batPct=100
17:17:14 8956 [DeviceTelemetryModule] (Sending): air_util_tx=3.073778, channel_utilization=0.000000, battery_level=100, voltage=4.156000
17:17:14 8956 [DeviceTelemetryModule] updateTelemetry LOCAL
17:17:14 8956 [DeviceTelemetryModule] Node status update: 2 online, 4 total
17:17:14 8956 [DeviceTelemetryModule] Sending packet to phone
17:17:14 8956 Telling client we have new packets 195
17:17:14 8956 [StreamAPI] getFromRadio=STATE_SEND_PACKETS
17:17:14 8956 [StreamAPI] phone downloaded packet (id=0x1d3ac2e3 Fr0x3c To0xff, WantAck0, HopLim3 Ch0x0 Portnum=67 rxtime=1666631834 priority=1)
17:17:14 8956 [StreamAPI] encoding toPhone packet to phone variant=2, 51 bytes
17:17:23 8965 [Power] Battery: usbPower=1, isCharging=0, batMv=4156, batPct=100
17:17:43 8985 [Power] Battery: usbPower=1, isCharging=0, batMv=4155, batPct=100
17:18:03 9005 [Power] Battery: usbPower=1, isCharging=0, batMv=4156, batPct=100
17:18:14 9016 [DeviceTelemetryModule] (Sending): air_util_tx=2.977083, channel_utilization=0.000000, battery_level=100, voltage=4.156000
17:18:14 9016 [DeviceTelemetryModule] updateTelemetry LOCAL
17:18:14 9016 [DeviceTelemetryModule] Node status update: 2 online, 4 total
17:18:14 9016 [DeviceTelemetryModule] Sending packet to mesh
17:18:14 9016 [DeviceTelemetryModule] Update DB node 0xf246b93c, rx_time=1666631894
17:18:14 9016 [DeviceTelemetryModule] handleReceived(LOCAL) (id=0x1d3ac2e4 Fr0x3c To0xff, WantAck0, HopLim3 Ch0x0 Portnum=67 rxtime=1666631894 priority=1)
17:18:14 9016 [DeviceTelemetryModule] No modules interested in portnum=67, src=LOCAL
17:18:14 9016 [DeviceTelemetryModule] Add packet record (id=0x1d3ac2e4 Fr0x3c To0xff, WantAck0, HopLim3 Ch0x0 Portnum=67 rxtime=1666631894 priority=1)
17:18:14 9016 [DeviceTelemetryModule] Should encrypt MQTT?: 1
17:18:14 9016 [DeviceTelemetryModule] Expanding short PSK #0
17:18:14 9016 [DeviceTelemetryModule] Using AES0 key!
17:18:14 9016 [DeviceTelemetryModule] enqueuing for send (id=0x1d3ac2e4 Fr0x3c To0xff, WantAck0, HopLim3 Ch0x2a encrypted rxtime=1666631894 priority=1)
17:18:14 9016 [DeviceTelemetryModule] txGood=87,rxGood=99,rxBad=0
17:18:14 9016 [DeviceTelemetryModule] Using channel 0 (hash 0x2a)
17:18:14 9016 [DeviceTelemetryModule] Expanding short PSK #0
17:18:14 9016 [DeviceTelemetryModule] Using AES0 key!
17:18:14 9016 [DeviceTelemetryModule] decoded message (id=0x1d3ac2e4 Fr0x3c To0xff, WantAck0, HopLim3 Ch0x0 Portnum=67 rxtime=1666631894 priority=1)
17:18:14 9016 Telling client we have new packets 196
17:18:14 9016 [RadioIf] Starting low level send (id=0x1d3ac2e4 Fr0x3c To0xff, WantAck0, HopLim3 Ch0x2a encrypted rxtime=1666631894 priority=1)
17:18:14 9016 [RadioIf] (bw=125, sf=12, cr=4/8) packet symLen=32 ms, payloadSize=39, time 3481 ms
17:18:14 9016 [RadioIf] AirTime - Packet transmitted : 3481ms
17:18:14 9016 [StreamAPI] getFromRadio=STATE_SEND_PACKETS
17:18:14 9016 [StreamAPI] phone downloaded packet (id=0x1d3ac2e4 Fr0x3c To0xff, WantAck0, HopLim3 Ch0x0 Portnum=67 rxtime=1666631894 priority=1)
17:18:14 9016 [StreamAPI] encoding toPhone packet to phone variant=2, 51 bytes
17:18:20 9022 [RadioIf] Completed sending (id=0x1d3ac2e4 Fr0x3c To0xff, WantAck0, HopLim3 Ch0x2a encrypted rxtime=1666631894 priority=1)
17:18:23 9025 [Power] Battery: usbPower=1, isCharging=0, batMv=4158, batPct=100
17:18:26 9028 [RadioIf] (bw=125, sf=12, cr=4/8) packet symLen=32 ms, payloadSize=39, time 3481 ms
17:18:26 9028 [RadioIf] Lora RX (id=0x1d3ac2e4 Fr0x3c To0xff, WantAck0, HopLim2 Ch0x2a encrypted rxSNR=-16.5 rxRSSI=1.84136)
17:18:26 9028 [RadioIf] AirTime - Packet received : 3481ms
17:18:26 9028 [Router] Rx someone rebroadcasting for us (id=0x1d3ac2e4 Fr0x3c To0xff, WantAck0, HopLim2 Ch0x2a encrypted rxSNR=-16.5 rxRSSI=1.84136)
17:18:26 9028 [Router] didn't find pending packet
17:18:26 9028 [Router] Found existing packet record for fr=0xf246b93c,to=0xffffffff,id=0x1d3ac2e4
17:18:26 9028 [Router] Found existing packet record for fr=0xf246b93c,to=0xffffffff,id=0x1d3ac2e4
17:18:26 9028 [Router] Add packet record (id=0x1d3ac2e4 Fr0x3c To0xff, WantAck0, HopLim2 Ch0x2a encrypted rxSNR=-16.5 rxRSSI=1.84136)
17:18:26 9028 [Router] Ignoring incoming msg, because we've already seen it (id=0x1d3ac2e4 Fr0x3c To0xff, WantAck0, HopLim2 Ch0x2a encrypted rxSNR=-16.5 rxRSSI=1.84136)
17:18:26 9028 [Router] Incoming message was filtered 0xf246b93c
17:18:30 9032 [NodeInfoModule] Sending our nodeinfo to mesh (wantReplies=0)
17:18:30 9032 [NodeInfoModule] cancelSending id=0x1d3ac2d1, removed=0
17:18:30 9032 [NodeInfoModule] sending owner !f246b93c/Dezmir/Dzm
17:18:30 9032 [NodeInfoModule] Update DB node 0xf246b93c, rx_time=1666631910
17:18:30 9032 [NodeInfoModule] handleReceived(LOCAL) (id=0x1d3ac2e5 Fr0x3c To0xff, WantAck0, HopLim3 Ch0x0 Portnum=4 rxtime=1666631910 priority=10)
17:18:30 9032 [NodeInfoModule] No modules interested in portnum=4, src=LOCAL
17:18:30 9032 [NodeInfoModule] Add packet record (id=0x1d3ac2e5 Fr0x3c To0xff, WantAck0, HopLim3 Ch0x0 Portnum=4 rxtime=1666631910 priority=10)
17:18:30 9032 [NodeInfoModule] Should encrypt MQTT?: 1
17:18:30 9032 [NodeInfoModule] Expanding short PSK #0
17:18:30 9032 [NodeInfoModule] Using AES0 key!
17:18:30 9032 [NodeInfoModule] enqueuing for send (id=0x1d3ac2e5 Fr0x3c To0xff, WantAck0, HopLim3 Ch0x2a encrypted rxtime=1666631910 priority=10)
17:18:30 9032 [NodeInfoModule] txGood=88,rxGood=100,rxBad=0
17:18:30 9032 [RadioIf] Starting low level send (id=0x1d3ac2e5 Fr0x3c To0xff, WantAck0, HopLim3 Ch0x2a encrypted rxtime=1666631910 priority=10)
17:18:30 9032 [RadioIf] (bw=125, sf=12, cr=4/8) packet symLen=32 ms, payloadSize=56, time 4366 ms
17:18:30 9032 [RadioIf] AirTime - Packet transmitted : 4366ms
17:18:37 9039 [RadioIf] Completed sending (id=0x1d3ac2e5 Fr0x3c To0xff, WantAck0, HopLim3 Ch0x2a encrypted rxtime=1666631910 priority=10)
17:18:43 9045 [Power] Battery: usbPower=1, isCharging=0, batMv=4156, batPct=100
17:19:02 9063 [GPS] WANT GPS=0
17:19:02 9063 [GPS] publishing pos@0:2, hasVal=0, GPSlock=0
17:19:02 9063 [GPS] WARNING: Using fixed position
17:19:02 9063 [GPS] onGPSChanged() pos@0, time=0, lat=467613330, lon=237129530, alt=425
17:19:02 9063 [GPS] updatePosition LOCAL pos@0, time=0, latI=467613330, lonI=237129530, alt=425
17:19:02 9063 [GPS] Node status update: 2 online, 4 total
17:19:03 9065 [Power] Battery: usbPower=1, isCharging=0, batMv=4156, batPct=100
17:19:05 9067 [PositionModule] Sending pos@0:6 to mesh (wantReplies=0)
17:19:05 9067 [PositionModule] cancelSending id=0x1d3ac2df, removed=0
17:19:05 9067 [PositionModule] Providing time to mesh 0
17:19:05 9067 [PositionModule] Position reply: time=0, latI=467613330, lonI=-237129530
17:19:05 9067 [PositionModule] Update DB node 0xf246b93c, rx_time=1666631945
17:19:05 9067 [PositionModule] handleReceived(LOCAL) (id=0x1d3ac2e6 Fr0x3c To0xff, WantAck0, HopLim3 Ch0x0 Portnum=3 rxtime=1666631945 priority=10)
17:19:05 9067 [PositionModule] No modules interested in portnum=3, src=LOCAL
17:19:05 9067 [PositionModule] Add packet record (id=0x1d3ac2e6 Fr0x3c To0xff, WantAck0, HopLim3 Ch0x0 Portnum=3 rxtime=1666631945 priority=10)
17:19:06 9067 [PositionModule] Should encrypt MQTT?: 1
17:19:06 9067 [PositionModule] Expanding short PSK #0
17:19:06 9067 [PositionModule] Using AES0 key!
17:19:06 9067 [PositionModule] enqueuing for send (id=0x1d3ac2e6 Fr0x3c To0xff, WantAck0, HopLim3 Ch0x2a encrypted rxtime=1666631945 priority=10)
17:19:06 9067 [PositionModule] txGood=89,rxGood=100,rxBad=0
17:19:06 9067 [PositionModule] Using channel 0 (hash 0x2a)
17:19:06 9067 [PositionModule] Expanding short PSK #0
17:19:06 9067 [PositionModule] Using AES0 key!
17:19:06 9067 [PositionModule] decoded message (id=0x1d3ac2e6 Fr0x3c To0xff, WantAck0, HopLim3 Ch0x0 Portnum=3 rxtime=1666631945 priority=10)
17:19:06 9067 Telling client we have new packets 197
17:19:06 9067 [StreamAPI] getFromRadio=STATE_SEND_PACKETS
17:19:06 9067 [StreamAPI] phone downloaded packet (id=0x1d3ac2e6 Fr0x3c To0xff, WantAck0, HopLim3 Ch0x0 Portnum=3 rxtime=1666631945 priority=10)
17:19:06 9067 [StreamAPI] encoding toPhone packet to phone variant=2, 45 bytes
17:19:06 9067 [RadioIf] Starting low level send (id=0x1d3ac2e6 Fr0x3c To0xff, WantAck0, HopLim3 Ch0x2a encrypted rxtime=1666631945 priority=10)
17:19:06 9067 [RadioIf] (bw=125, sf=12, cr=4/8) packet symLen=32 ms, payloadSize=33, time 3153 ms
17:19:06 9068 [RadioIf] AirTime - Packet transmitted : 3153ms
17:19:11 9073 [RadioIf] Completed sending (id=0x1d3ac2e6 Fr0x3c To0xff, WantAck0, HopLim3 Ch0x2a encrypted rxtime=1666631945 priority=10)
17:19:14 9076 [DeviceTelemetryModule] (Sending): air_util_tx=3.073778, channel_utilization=18.333334, battery_level=100, voltage=4.156000
17:19:14 9076 [DeviceTelemetryModule] updateTelemetry LOCAL
17:19:14 9076 [DeviceTelemetryModule] Node status update: 2 online, 4 total
17:19:14 9076 [DeviceTelemetryModule] Sending packet to phone
17:19:14 9076 Telling client we have new packets 198
17:19:14 9076 [StreamAPI] getFromRadio=STATE_SEND_PACKETS
17:19:14 9076 [StreamAPI] phone downloaded packet (id=0x1d3ac2e7 Fr0x3c To0xff, WantAck0, HopLim3 Ch0x0 Portnum=67 rxtime=1666631954 priority=1)
17:19:14 9076 [StreamAPI] encoding toPhone packet to phone variant=2, 56 bytes
17:19:17 9079 [RadioIf] (bw=125, sf=12, cr=4/8) packet symLen=32 ms, payloadSize=33, time 3153 ms
17:19:17 9079 [RadioIf] Lora RX (id=0x1d3ac2e6 Fr0x3c To0xff, WantAck0, HopLim2 Ch0x2a encrypted rxSNR=-16.5 rxRSSI=1.84136)
17:19:17 9079 [RadioIf] AirTime - Packet received : 3153ms
17:19:17 9079 [Router] Rx someone rebroadcasting for us (id=0x1d3ac2e6 Fr0x3c To0xff, WantAck0, HopLim2 Ch0x2a encrypted rxSNR=-16.5 rxRSSI=1.84136)
17:19:17 9079 [Router] didn't find pending packet
17:19:17 9079 [Router] Found existing packet record for fr=0xf246b93c,to=0xffffffff,id=0x1d3ac2e6
17:19:17 9079 [Router] Found existing packet record for fr=0xf246b93c,to=0xffffffff,id=0x1d3ac2e6
17:19:17 9079 [Router] Add packet record (id=0x1d3ac2e6 Fr0x3c To0xff, WantAck0, HopLim2 Ch0x2a encrypted rxSNR=-16.5 rxRSSI=1.84136)
17:19:17 9079 [Router] Ignoring incoming msg, because we've already seen it (id=0x1d3ac2e6 Fr0x3c To0xff, WantAck0, HopLim2 Ch0x2a encrypted rxSNR=-16.5 rxRSSI=1.84136)
17:19:17 9079 [Router] Incoming message was filtered 0xf246b93c
17:19:23 9085 [Power] Battery: usbPower=1, isCharging=0, batMv=4156, batPct=100
17:19:43 9105 [Power] Battery: usbPower=1, isCharging=0, batMv=4156, batPct=100
17:20:03 9125 [Power] Battery: usbPower=1, isCharging=0, batMv=4156, batPct=100
17:20:14 9136 [DeviceTelemetryModule] (Sending): air_util_tx=3.073778, channel_utilization=5.255000, battery_level=100, voltage=4.156000
17:20:14 9136 [DeviceTelemetryModule] updateTelemetry LOCAL
17:20:14 9136 [DeviceTelemetryModule] Node status update: 2 online, 4 total
17:20:14 9136 [DeviceTelemetryModule] Sending packet to phone
17:20:14 9136 Telling client we have new packets 199
17:20:14 9136 [StreamAPI] getFromRadio=STATE_SEND_PACKETS
17:20:14 9136 [StreamAPI] phone downloaded packet (id=0x1d3ac2e8 Fr0x3c To0xff, WantAck0, HopLim3 Ch0x0 Portnum=67 rxtime=1666632014 priority=1)
17:20:14 9136 [StreamAPI] encoding toPhone packet to phone variant=2, 56 bytes
17:20:23 9145 [Power] Battery: usbPower=1, isCharging=0, batMv=4156, batPct=100
17:20:43 9165 [Power] Battery: usbPower=1, isCharging=0, batMv=4158, batPct=100
17:21:02 9184 [GPS] WANT GPS=1
17:21:03 9185 [Power] Battery: usbPower=1, isCharging=0, batMv=4156, batPct=100
17:21:14 9196 [DeviceTelemetryModule] (Sending): air_util_tx=3.073778, channel_utilization=0.000000, battery_level=100, voltage=4.156000
17:21:14 9196 [DeviceTelemetryModule] updateTelemetry LOCAL
17:21:14 9196 [DeviceTelemetryModule] Node status update: 2 online, 4 total
17:21:14 9196 [DeviceTelemetryModule] Sending packet to phone
17:21:14 9196 Telling client we have new packets 200
17:21:14 9196 [StreamAPI] getFromRadio=STATE_SEND_PACKETS
17:21:14 9196 [StreamAPI] phone downloaded packet (id=0x1d3ac2e9 Fr0x3c To0xff, WantAck0, HopLim3 Ch0x0 Portnum=67 rxtime=1666632074 priority=1)
17:21:14 9196 [StreamAPI] encoding toPhone packet to phone variant=2, 51 bytes
17:21:23 9205 [Power] Battery: usbPower=1, isCharging=0, batMv=4156, batPct=100
17:21:43 9225 [Power] Battery: usbPower=1, isCharging=0, batMv=4158, batPct=100
17:22:03 9245 [Power] Battery: usbPower=1, isCharging=0, batMv=4156, batPct=100
17:22:14 9256 [DeviceTelemetryModule] (Sending): air_util_tx=3.073778, channel_utilization=0.000000, battery_level=100, voltage=4.156000
17:22:14 9256 [DeviceTelemetryModule] updateTelemetry LOCAL
17:22:14 9256 [DeviceTelemetryModule] Node status update: 2 online, 4 total
17:22:14 9256 [DeviceTelemetryModule] Sending packet to phone
17:22:14 9256 Telling client we have new packets 201
17:22:14 9256 [StreamAPI] getFromRadio=STATE_SEND_PACKETS
17:22:14 9256 [StreamAPI] phone downloaded packet (id=0x1d3ac2ea Fr0x3c To0xff, WantAck0, HopLim3 Ch0x0 Portnum=67 rxtime=1666632134 priority=1)
17:22:14 9256 [StreamAPI] encoding toPhone packet to phone variant=2, 51 bytes
17:22:23 9265 [Power] Battery: usbPower=1, isCharging=0, batMv=4156, batPct=100
17:22:43 9285 [Power] Battery: usbPower=1, isCharging=0, batMv=4156, batPct=100
17:23:03 9305 [Power] Battery: usbPower=1, isCharging=0, batMv=4156, batPct=100
17:23:14 9316 [DeviceTelemetryModule] (Sending): air_util_tx=3.073778, channel_utilization=0.000000, battery_level=100, voltage=4.156000
17:23:14 9316 [DeviceTelemetryModule] updateTelemetry LOCAL
17:23:14 9316 [DeviceTelemetryModule] Node status update: 2 online, 4 total
17:23:14 9316 [DeviceTelemetryModule] Sending packet to phone
17:23:14 9316 Telling client we have new packets 202
17:23:14 9316 [StreamAPI] getFromRadio=STATE_SEND_PACKETS
17:23:14 9316 [StreamAPI] phone downloaded packet (id=0x1d3ac2eb Fr0x3c To0xff, WantAck0, HopLim3 Ch0x0 Portnum=67 rxtime=1666632194 priority=1)
17:23:14 9316 [StreamAPI] encoding toPhone packet to phone variant=2, 51 bytes
17:23:23 9325 [Power] Battery: usbPower=1, isCharging=0, batMv=4155, batPct=100
17:23:43 9345 [Power] Battery: usbPower=1, isCharging=0, batMv=4156, batPct=100
17:24:03 9365 [Power] Battery: usbPower=1, isCharging=0, batMv=4156, batPct=100
17:24:06 9367 [PositionModule] Sending pos@0:6 to mesh (wantReplies=0)
17:24:06 9367 [PositionModule] cancelSending id=0x1d3ac2e6, removed=0
17:24:06 9367 [PositionModule] Providing time to mesh 0
17:24:06 9367 [PositionModule] Position reply: time=0, latI=467613330, lonI=-237129530
17:24:06 9367 [PositionModule] Update DB node 0xf246b93c, rx_time=1666632246
17:24:06 9367 [PositionModule] handleReceived(LOCAL) (id=0x1d3ac2ec Fr0x3c To0xff, WantAck0, HopLim3 Ch0x0 Portnum=3 rxtime=1666632246 priority=10)
17:24:06 9367 [PositionModule] No modules interested in portnum=3, src=LOCAL
17:24:06 9367 [PositionModule] Add packet record (id=0x1d3ac2ec Fr0x3c To0xff, WantAck0, HopLim3 Ch0x0 Portnum=3 rxtime=1666632246 priority=10)
17:24:06 9367 [PositionModule] Should encrypt MQTT?: 1
17:24:06 9367 [PositionModule] Expanding short PSK #0
17:24:06 9367 [PositionModule] Using AES0 key!
17:24:06 9367 [PositionModule] enqueuing for send (id=0x1d3ac2ec Fr0x3c To0xff, WantAck0, HopLim3 Ch0x2a encrypted rxtime=1666632246 priority=10)
17:24:06 9367 [PositionModule] txGood=90,rxGood=101,rxBad=0
17:24:06 9367 [PositionModule] Using channel 0 (hash 0x2a)
17:24:06 9367 [PositionModule] Expanding short PSK #0
17:24:06 9367 [PositionModule] Using AES0 key!
17:24:06 9367 [PositionModule] decoded message (id=0x1d3ac2ec Fr0x3c To0xff, WantAck0, HopLim3 Ch0x0 Portnum=3 rxtime=1666632246 priority=10)
17:24:06 9367 Telling client we have new packets 203
17:24:06 9368 [RadioIf] Starting low level send (id=0x1d3ac2ec Fr0x3c To0xff, WantAck0, HopLim3 Ch0x2a encrypted rxtime=1666632246 priority=10)
17:24:06 9368 [RadioIf] (bw=125, sf=12, cr=4/8) packet symLen=32 ms, payloadSize=33, time 3153 ms
17:24:06 9368 [RadioIf] AirTime - Packet transmitted : 3153ms
17:24:06 9368 [StreamAPI] getFromRadio=STATE_SEND_PACKETS
17:24:06 9368 [StreamAPI] phone downloaded packet (id=0x1d3ac2ec Fr0x3c To0xff, WantAck0, HopLim3 Ch0x0 Portnum=3 rxtime=1666632246 priority=10)
17:24:06 9368 [StreamAPI] encoding toPhone packet to phone variant=2, 45 bytes
17:24:11 9373 [RadioIf] Completed sending (id=0x1d3ac2ec Fr0x3c To0xff, WantAck0, HopLim3 Ch0x2a encrypted rxtime=1666632246 priority=10)
17:24:14 9376 [DeviceTelemetryModule] (Sending): air_util_tx=3.073778, channel_utilization=5.255000, battery_level=100, voltage=4.156000
17:24:14 9376 [DeviceTelemetryModule] updateTelemetry LOCAL
17:24:14 9376 [DeviceTelemetryModule] Node status update: 2 online, 4 total
17:24:14 9376 [DeviceTelemetryModule] Sending packet to phone
17:24:14 9376 Telling client we have new packets 204
17:24:14 9376 [StreamAPI] getFromRadio=STATE_SEND_PACKETS
17:24:14 9376 [StreamAPI] phone downloaded packet (id=0x1d3ac2ed Fr0x3c To0xff, WantAck0, HopLim3 Ch0x0 Portnum=67 rxtime=1666632254 priority=1)
17:24:14 9376 [StreamAPI] encoding toPhone packet to phone variant=2, 56 bytes
17:24:17 9379 [RadioIf] (bw=125, sf=12, cr=4/8) packet symLen=32 ms, payloadSize=33, time 3153 ms
17:24:17 9379 [RadioIf] Lora RX (id=0x1d3ac2ec Fr0x3c To0xff, WantAck0, HopLim2 Ch0x2a encrypted rxSNR=-15.75 rxRSSI=1.84136)
17:24:17 9379 [RadioIf] AirTime - Packet received : 3153ms
17:24:17 9379 [Router] Rx someone rebroadcasting for us (id=0x1d3ac2ec Fr0x3c To0xff, WantAck0, HopLim2 Ch0x2a encrypted rxSNR=-15.75 rxRSSI=1.84136)
17:24:17 9379 [Router] didn't find pending packet
17:24:17 9379 [Router] Found existing packet record for fr=0xf246b93c,to=0xffffffff,id=0x1d3ac2ec
17:24:17 9379 [Router] Found existing packet record for fr=0xf246b93c,to=0xffffffff,id=0x1d3ac2ec
17:24:17 9379 [Router] Add packet record (id=0x1d3ac2ec Fr0x3c To0xff, WantAck0, HopLim2 Ch0x2a encrypted rxSNR=-15.75 rxRSSI=1.84136)
17:24:17 9379 [Router] Ignoring incoming msg, because we've already seen it (id=0x1d3ac2ec Fr0x3c To0xff, WantAck0, HopLim2 Ch0x2a encrypted rxSNR=-15.75 rxRSSI=1.84136)
17:24:17 9379 [Router] Incoming message was filtered 0xf246b93c
17:24:23 9385 [Power] Battery: usbPower=1, isCharging=0, batMv=4156, batPct=100
17:24:43 9405 [Power] Battery: usbPower=1, isCharging=0, batMv=4156, batPct=100
17:25:03 9425 [Power] Battery: usbPower=1, isCharging=0, batMv=4156, batPct=100
17:25:14 9436 [DeviceTelemetryModule] (Sending): air_util_tx=3.073778, channel_utilization=0.000000, battery_level=100, voltage=4.156000
17:25:14 9436 [DeviceTelemetryModule] updateTelemetry LOCAL
17:25:14 9436 [DeviceTelemetryModule] Node status update: 2 online, 4 total
17:25:14 9436 [DeviceTelemetryModule] Sending packet to phone
17:25:14 9436 Telling client we have new packets 205
17:25:14 9436 [StreamAPI] getFromRadio=STATE_SEND_PACKETS
17:25:14 9436 [StreamAPI] phone downloaded packet (id=0x1d3ac2ee Fr0x3c To0xff, WantAck0, HopLim3 Ch0x0 Portnum=67 rxtime=1666632314 priority=1)
17:25:14 9436 [StreamAPI] encoding toPhone packet to phone variant=2, 51 bytes
17:25:23 9445 [Power] Battery: usbPower=1, isCharging=0, batMv=4156, batPct=100
17:25:33 9455 [RadioIf] (bw=125, sf=12, cr=4/8) packet symLen=32 ms, payloadSize=38, time 3416 ms
17:25:33 9455 [RadioIf] Lora RX (id=0x3abcaae7 Fr0x0c To0xff, WantAck0, HopLim3 Ch0x2a encrypted rxSNR=-15.5 rxRSSI=1.84136)
17:25:33 9455 [RadioIf] AirTime - Packet received : 3416ms
17:25:33 9455 [Router] Add packet record (id=0x3abcaae7 Fr0x0c To0xff, WantAck0, HopLim3 Ch0x2a encrypted rxSNR=-15.5 rxRSSI=1.84136)
17:25:33 9455 [Router] Using channel 0 (hash 0x2a)
17:25:33 9455 [Router] Expanding short PSK #0
17:25:33 9455 [Router] Using AES0 key!
17:25:33 9455 [Router] decoded message (id=0x3abcaae7 Fr0x0c To0xff, WantAck0, HopLim3 Ch0x0 Portnum=3 rxtime=1666632333 rxSNR=-15.5 rxRSSI=1.84136)
17:25:33 9455 [Router] handleReceived(REMOTE) (id=0x3abcaae7 Fr0x0c To0xff, WantAck0, HopLim3 Ch0x0 Portnum=3 rxtime=1666632333 rxSNR=-15.5 rxRSSI=1.84136)
17:25:33 9455 [Router] Module 'position' wantsPacket=1
17:25:33 9455 [Router] Received position from=0xf246a50c, id=0x3abcaae7, portnum=3, payloadlen=18
17:25:33 9455 [Router] POSITION node=f246a50c l=18 LAT LON MSL TIME 
17:25:33 9455 [Router] updatePosition REMOTE node=0xf246a50c time=1666632329, latI=467445545, lonI=235717400
17:25:33 9455 [Router] Node status update: 2 online, 4 total
17:25:33 9455 [Router] Module 'position' considered
17:25:33 9455 [Router] Module 'routing' wantsPacket=1
17:25:33 9455 [Router] Received routing from=0xf246a50c, id=0x3abcaae7, portnum=3, payloadlen=18
17:25:33 9455 [Router] Routing sniffing (id=0x3abcaae7 Fr0x0c To0xff, WantAck0, HopLim3 Ch0x0 Portnum=3 rxtime=1666632333 rxSNR=-15.5 rxRSSI=1.84136)
17:25:33 9455 [Router] Rebroadcasting received floodmsg to neighbors (id=0x3abcaae7 Fr0x0c To0xff, WantAck0, HopLim3 Ch0x0 Portnum=3 rxtime=1666632333 rxSNR=-15.5 rxRSSI=1.84136)
17:25:33 9455 [Router] Should encrypt MQTT?: 1
17:25:33 9455 [Router] Expanding short PSK #0
17:25:33 9455 [Router] Using AES0 key!
17:25:33 9455 [Router] enqueuing for send (id=0x3abcaae7 Fr0x0c To0xff, WantAck0, HopLim2 Ch0x2a encrypted rxtime=1666632333 rxSNR=-15.5 rxRSSI=1.84136)
17:25:33 9455 [Router] txGood=91,rxGood=103,rxBad=0
17:25:33 9455 [Router] rx_snr found. hop_limit:2 rx_snr:-15.500000
17:25:33 9455 [Router] rx_snr found in packet. Setting tx delay:42
17:25:33 9455 [Router] FIXME-update-db Sniffing packet
17:25:33 9455 [Router] Delivering rx packet (id=0x3abcaae7 Fr0x0c To0xff, WantAck0, HopLim3 Ch0x0 Portnum=3 rxtime=1666632333 rxSNR=-15.5 rxRSSI=1.84136)
17:25:33 9455 [Router] Forwarding to phone (id=0x3abcaae7 Fr0x0c To0xff, WantAck0, HopLim3 Ch0x0 Portnum=3 rxtime=1666632333 rxSNR=-15.5 rxRSSI=1.84136)
17:25:33 9455 [Router] Update DB node 0xf246a50c, rx_time=1666632333
17:25:33 9455 [Router] Module 'routing' considered
17:25:33 9455 Telling client we have new packets 206
17:25:33 9455 [RadioIf] Starting low level send (id=0x3abcaae7 Fr0x0c To0xff, WantAck0, HopLim2 Ch0x2a encrypted rxtime=1666632333 rxSNR=-15.5 rxRSSI=1.84136 priority=64)
17:25:33 9455 [RadioIf] (bw=125, sf=12, cr=4/8) packet symLen=32 ms, payloadSize=38, time 3416 ms
17:25:33 9455 [RadioIf] AirTime - Packet transmitted : 3416ms
17:25:33 9455 [StreamAPI] getFromRadio=STATE_SEND_PACKETS
17:25:33 9455 [StreamAPI] phone downloaded packet (id=0x3abcaae7 Fr0x0c To0xff, WantAck0, HopLim3 Ch0x0 Portnum=3 rxtime=1666632333 rxSNR=-15.5 rxRSSI=1.84136)
17:25:33 9455 [StreamAPI] encoding toPhone packet to phone variant=2, 64 bytes
17:25:39 9461 [RadioIf] Completed sending (id=0x3abcaae7 Fr0x0c To0xff, WantAck0, HopLim2 Ch0x2a encrypted rxtime=1666632333 rxSNR=-15.5 rxRSSI=1.84136 priority=64)
17:25:43 9465 [Power] Battery: usbPower=1, isCharging=0, batMv=4156, batPct=100
17:26:03 9485 [Power] Battery: usbPower=1, isCharging=0, batMv=4156, batPct=100
17:26:14 9496 [DeviceTelemetryModule] (Sending): air_util_tx=3.073778, channel_utilization=11.386666, battery_level=100, voltage=4.156000
17:26:14 9496 [DeviceTelemetryModule] updateTelemetry LOCAL
17:26:14 9496 [DeviceTelemetryModule] Node status update: 2 online, 4 total
17:26:14 9496 [DeviceTelemetryModule] Sending packet to phone
17:26:14 9496 Telling client we have new packets 207
17:26:14 9496 [StreamAPI] getFromRadio=STATE_SEND_PACKETS
17:26:14 9496 [StreamAPI] phone downloaded packet (id=0x1d3ac2ef Fr0x3c To0xff, WantAck0, HopLim3 Ch0x0 Portnum=67 rxtime=1666632374 priority=1)
17:26:14 9496 [StreamAPI] encoding toPhone packet to phone variant=2, 56 bytes
17:26:23 9505 [Power] Battery: usbPower=1, isCharging=0, batMv=4156, batPct=100
[HTTPS:I] New connection. Socket FID=53
[HTTPS:I] Request: GET / (FID=53)
[9516254][E][vfs_api.cpp:104] open(): /littlefs/static/index.html does not exist, no permits for creation
[9516277][E][vfs_api.cpp:283] VFSFileImpl(): fopen(/littlefs/static/index.html.gz) failed
[9516301][E][vfs_api.cpp:283] VFSFileImpl(): fopen(/littlefs/static/index.html.gz) failed
17:26:34 9516 [WebServerThread] File not available - /static/index.html.gz
17:26:43 9525 [Power] Battery: usbPower=1, isCharging=0, batMv=4156, batPct=100
[HTTPS:I] Client closed connection, FID=53
[HTTPS:I] Client closed (FID=53, cstate=2)
[HTTPS:I] Connection closed. Socket FID=53
17:27:03 9545 [Power] Battery: usbPower=1, isCharging=0, batMv=4156, batPct=100
17:27:14 9556 [DeviceTelemetryModule] (Sending): air_util_tx=3.073778, channel_utilization=0.000000, battery_level=100, voltage=4.156000
17:27:14 9556 [DeviceTelemetryModule] updateTelemetry LOCAL
17:27:14 9556 [DeviceTelemetryModule] Node status update: 2 online, 4 total
17:27:14 9556 [DeviceTelemetryModule] Sending packet to phone
17:27:14 9556 Telling client we have new packets 208
17:27:14 9556 [StreamAPI] getFromRadio=STATE_SEND_PACKETS
17:27:14 9556 [StreamAPI] phone downloaded packet (id=0x1d3ac2f0 Fr0x3c To0xff, WantAck0, HopLim3 Ch0x0 Portnum=67 rxtime=1666632434 priority=1)
17:27:14 9556 [StreamAPI] encoding toPhone packet to phone variant=2, 51 bytes
17:27:15 9557 [Button] Enter state: POWER
17:27:15 9557 [Screen] Screen: Unpowered...
17:27:15 9557 [Screen] Screen: Powered...
17:27:17 9559 [Button] Enter state: POWER
17:27:17 9559 [Screen] Screen: Unpowered...
17:27:17 9559 [Screen] Screen: Powered...
17:27:18 9560 [Button] Enter state: POWER
17:27:18 9560 [Screen] Screen: Unpowered...
17:27:18 9560 [Screen] Screen: Powered...
17:27:20 9561 [Button] Enter state: POWER
17:27:20 9561 [Screen] Screen: Unpowered...
17:27:20 9561 [Screen] Screen: Powered...
17:27:22 9563 [Button] Enter state: POWER
17:27:22 9563 [Screen] Screen: Unpowered...
17:27:22 9563 [Screen] Screen: Powered...

Continued in the next post…

17:27:23 9565 [Power] Battery: usbPower=1, isCharging=0, batMv=4156, batPct=100
17:27:25 9566 [RadioIf] (bw=125, sf=12, cr=4/8) packet symLen=32 ms, payloadSize=56, time 4366 ms
17:27:25 9566 [RadioIf] Lora RX (id=0x3abcaae8 Fr0x0c To0xff, WantAck0, HopLim3 Ch0x2a encrypted rxSNR=-17 rxRSSI=1.84136)
17:27:25 9566 [RadioIf] AirTime - Packet received : 4366ms
17:27:25 9566 [Router] Add packet record (id=0x3abcaae8 Fr0x0c To0xff, WantAck0, HopLim3 Ch0x2a encrypted rxSNR=-17 rxRSSI=1.84136)
17:27:25 9566 [Router] Using channel 0 (hash 0x2a)
17:27:25 9566 [Router] Expanding short PSK #0
17:27:25 9566 [Router] Using AES0 key!
17:27:25 9566 [Router] decoded message (id=0x3abcaae8 Fr0x0c To0xff, WantAck0, HopLim3 Ch0x0 Portnum=4 rxtime=1666632445 rxSNR=-17 rxRSSI=1.84136)
17:27:25 9566 [Router] handleReceived(REMOTE) (id=0x3abcaae8 Fr0x0c To0xff, WantAck0, HopLim3 Ch0x0 Portnum=4 rxtime=1666632445 rxSNR=-17 rxRSSI=1.84136)
17:27:25 9566 [Router] Module 'nodeinfo' wantsPacket=1
17:27:25 9566 [Router] Received nodeinfo from=0xf246a50c, id=0x3abcaae8, portnum=4, payloadlen=36
17:27:25 9566 [Router] old user !f246a50c/Campului/Cmp
17:27:25 9566 [Router] updating changed=0 user !f246a50c/Campului/Cmp
17:27:25 9566 [Router] Module 'nodeinfo' considered
17:27:25 9566 [Router] Module 'routing' wantsPacket=1
17:27:25 9566 [Router] Received routing from=0xf246a50c, id=0x3abcaae8, portnum=4, payloadlen=36
17:27:25 9566 [Router] Routing sniffing (id=0x3abcaae8 Fr0x0c To0xff, WantAck0, HopLim3 Ch0x0 Portnum=4 rxtime=1666632445 rxSNR=-17 rxRSSI=1.84136)
17:27:25 9566 [Router] Rebroadcasting received floodmsg to neighbors (id=0x3abcaae8 Fr0x0c To0xff, WantAck0, HopLim3 Ch0x0 Portnum=4 rxtime=1666632445 rxSNR=-17 rxRSSI=1.84136)
17:27:25 9566 [Router] Should encrypt MQTT?: 1
17:27:25 9566 [Router] Expanding short PSK #0
17:27:25 9566 [Router] Using AES0 key!
17:27:25 9566 [Router] enqueuing for send (id=0x3abcaae8 Fr0x0c To0xff, WantAck0, HopLim2 Ch0x2a encrypted rxtime=1666632445 rxSNR=-17 rxRSSI=1.84136)
17:27:25 9566 [Router] txGood=92,rxGood=104,rxBad=0
17:27:25 9566 [Router] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:25 9566 [Router] rx_snr found in packet. Setting tx delay:84
17:27:25 9566 [Router] FIXME-update-db Sniffing packet
17:27:25 9566 [Router] Delivering rx packet (id=0x3abcaae8 Fr0x0c To0xff, WantAck0, HopLim3 Ch0x0 Portnum=4 rxtime=1666632445 rxSNR=-17 rxRSSI=1.84136)
17:27:25 9566 [Router] Forwarding to phone (id=0x3abcaae8 Fr0x0c To0xff, WantAck0, HopLim3 Ch0x0 Portnum=4 rxtime=1666632445 rxSNR=-17 rxRSSI=1.84136)
17:27:25 9566 [Router] Update DB node 0xf246a50c, rx_time=1666632445
17:27:25 9566 [Router] Module 'routing' considered
17:27:25 9566 [Screen] Screen: Joined: Campului
17:27:25 9566 Telling client we have new packets 209
17:27:25 9566 [StreamAPI] getFromRadio=STATE_SEND_PACKETS
17:27:25 9566 [StreamAPI] phone downloaded packet (id=0x3abcaae8 Fr0x0c To0xff, WantAck0, HopLim3 Ch0x0 Portnum=4 rxtime=1666632445 rxSNR=-17 rxRSSI=1.84136)
17:27:25 9566 [StreamAPI] encoding toPhone packet to phone variant=2, 82 bytes
17:27:25 9567 [RadioIf] Can not send yet, busyRx
17:27:25 9567 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:25 9567 [RadioIf] rx_snr found in packet. Setting tx delay:84
17:27:25 9567 [RadioIf] Can not send yet, busyRx
17:27:25 9567 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:25 9567 [RadioIf] rx_snr found in packet. Setting tx delay:42
17:27:25 9567 [RadioIf] Can not send yet, busyRx
17:27:25 9567 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:25 9567 [RadioIf] rx_snr found in packet. Setting tx delay:84
17:27:25 9567 [RadioIf] Can not send yet, busyRx
17:27:25 9567 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:25 9567 [RadioIf] rx_snr found in packet. Setting tx delay:42
17:27:25 9567 [RadioIf] Can not send yet, busyRx
17:27:25 9567 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:25 9567 [RadioIf] rx_snr found in packet. Setting tx delay:126
17:27:25 9567 [RadioIf] Can not send yet, busyRx
17:27:25 9567 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:25 9567 [RadioIf] rx_snr found in packet. Setting tx delay:42
17:27:25 9567 [RadioIf] Can not send yet, busyRx
17:27:25 9567 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:25 9567 [RadioIf] rx_snr found in packet. Setting tx delay:84
17:27:25 9567 [RadioIf] Can not send yet, busyRx
17:27:25 9567 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:25 9567 [RadioIf] rx_snr found in packet. Setting tx delay:42
17:27:25 9567 [RadioIf] Can not send yet, busyRx
17:27:25 9567 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:25 9567 [RadioIf] rx_snr found in packet. Setting tx delay:126
17:27:26 9567 [RadioIf] Can not send yet, busyRx
17:27:26 9567 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:26 9567 [RadioIf] rx_snr found in packet. Setting tx delay:0
17:27:26 9567 [RadioIf] Can not send yet, busyRx
17:27:26 9567 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:26 9567 [RadioIf] rx_snr found in packet. Setting tx delay:84
17:27:26 9567 [RadioIf] Can not send yet, busyRx
17:27:26 9567 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:26 9567 [RadioIf] rx_snr found in packet. Setting tx delay:126
17:27:26 9568 [RadioIf] Can not send yet, busyRx
17:27:26 9568 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:26 9568 [RadioIf] rx_snr found in packet. Setting tx delay:42
17:27:26 9568 [RadioIf] Can not send yet, busyRx
17:27:26 9568 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:26 9568 [RadioIf] rx_snr found in packet. Setting tx delay:84
17:27:26 9568 [RadioIf] Can not send yet, busyRx
17:27:26 9568 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:26 9568 [RadioIf] rx_snr found in packet. Setting tx delay:0
17:27:26 9568 [RadioIf] Can not send yet, busyRx
17:27:26 9568 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:26 9568 [RadioIf] rx_snr found in packet. Setting tx delay:84
17:27:26 9568 [RadioIf] Can not send yet, busyRx
17:27:26 9568 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:26 9568 [RadioIf] rx_snr found in packet. Setting tx delay:0
17:27:26 9568 [RadioIf] Can not send yet, busyRx
17:27:26 9568 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:26 9568 [RadioIf] rx_snr found in packet. Setting tx delay:42
17:27:26 9568 [RadioIf] Can not send yet, busyRx
17:27:26 9568 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:26 9568 [RadioIf] rx_snr found in packet. Setting tx delay:126
17:27:26 9568 [RadioIf] Can not send yet, busyRx
17:27:26 9568 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:26 9568 [RadioIf] rx_snr found in packet. Setting tx delay:84
17:27:26 9568 [RadioIf] Can not send yet, busyRx
17:27:26 9568 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:26 9568 [RadioIf] rx_snr found in packet. Setting tx delay:126
17:27:27 9568 [RadioIf] Can not send yet, busyRx
17:27:27 9568 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:27 9568 [RadioIf] rx_snr found in packet. Setting tx delay:0
17:27:27 9568 [RadioIf] Can not send yet, busyRx
17:27:27 9568 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:27 9568 [RadioIf] rx_snr found in packet. Setting tx delay:42
17:27:27 9568 [RadioIf] Can not send yet, busyRx
17:27:27 9568 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:27 9568 [RadioIf] rx_snr found in packet. Setting tx delay:126
17:27:27 9569 [RadioIf] Can not send yet, busyRx
17:27:27 9569 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:27 9569 [RadioIf] rx_snr found in packet. Setting tx delay:42
17:27:27 9569 [RadioIf] Can not send yet, busyRx
17:27:27 9569 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:27 9569 [RadioIf] rx_snr found in packet. Setting tx delay:0
17:27:27 9569 [RadioIf] Can not send yet, busyRx
17:27:27 9569 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:27 9569 [RadioIf] rx_snr found in packet. Setting tx delay:0
17:27:27 9569 [RadioIf] Can not send yet, busyRx
17:27:27 9569 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:27 9569 [RadioIf] rx_snr found in packet. Setting tx delay:42
17:27:27 9569 [RadioIf] Can not send yet, busyRx
17:27:27 9569 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:27 9569 [RadioIf] rx_snr found in packet. Setting tx delay:0
17:27:27 9569 [RadioIf] Can not send yet, busyRx
17:27:27 9569 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:27 9569 [RadioIf] rx_snr found in packet. Setting tx delay:42
17:27:27 9569 [RadioIf] Can not send yet, busyRx
17:27:27 9569 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:27 9569 [RadioIf] rx_snr found in packet. Setting tx delay:0
17:27:27 9569 [RadioIf] Can not send yet, busyRx
17:27:27 9569 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:27 9569 [RadioIf] rx_snr found in packet. Setting tx delay:0
17:27:27 9569 [RadioIf] Can not send yet, busyRx
17:27:27 9569 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:27 9569 [RadioIf] rx_snr found in packet. Setting tx delay:84
17:27:27 9569 [RadioIf] Can not send yet, busyRx
17:27:27 9569 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:27 9569 [RadioIf] rx_snr found in packet. Setting tx delay:126
17:27:27 9569 [RadioIf] Can not send yet, busyRx
17:27:27 9569 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:27 9569 [RadioIf] rx_snr found in packet. Setting tx delay:84
17:27:27 9569 [RadioIf] Can not send yet, busyRx
17:27:27 9569 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:27 9569 [RadioIf] rx_snr found in packet. Setting tx delay:42
17:27:27 9569 [RadioIf] Can not send yet, busyRx
17:27:27 9569 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:27 9569 [RadioIf] rx_snr found in packet. Setting tx delay:126
17:27:28 9569 [RadioIf] Can not send yet, busyRx
17:27:28 9569 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:28 9569 [RadioIf] rx_snr found in packet. Setting tx delay:42
17:27:28 9569 [RadioIf] Can not send yet, busyRx
17:27:28 9569 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:28 9569 [RadioIf] rx_snr found in packet. Setting tx delay:84
17:27:28 9569 [RadioIf] Can not send yet, busyRx
17:27:28 9569 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:28 9569 [RadioIf] rx_snr found in packet. Setting tx delay:0
17:27:28 9569 [RadioIf] Can not send yet, busyRx
17:27:28 9569 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:28 9569 [RadioIf] rx_snr found in packet. Setting tx delay:126
17:27:28 9570 [RadioIf] Can not send yet, busyRx
17:27:28 9570 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:28 9570 [RadioIf] rx_snr found in packet. Setting tx delay:0
17:27:28 9570 [RadioIf] Can not send yet, busyRx
17:27:28 9570 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:28 9570 [RadioIf] rx_snr found in packet. Setting tx delay:42
17:27:28 9570 [RadioIf] Can not send yet, busyRx
17:27:28 9570 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:28 9570 [RadioIf] rx_snr found in packet. Setting tx delay:126
17:27:28 9570 [RadioIf] Can not send yet, busyRx
17:27:28 9570 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:28 9570 [RadioIf] rx_snr found in packet. Setting tx delay:84
17:27:28 9570 [RadioIf] Can not send yet, busyRx
17:27:28 9570 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:28 9570 [RadioIf] rx_snr found in packet. Setting tx delay:126
17:27:28 9570 [RadioIf] Can not send yet, busyRx
17:27:28 9570 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:28 9570 [RadioIf] rx_snr found in packet. Setting tx delay:0
17:27:28 9570 [RadioIf] Can not send yet, busyRx
17:27:28 9570 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:28 9570 [RadioIf] rx_snr found in packet. Setting tx delay:0
17:27:28 9570 [RadioIf] Can not send yet, busyRx
17:27:28 9570 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:28 9570 [RadioIf] rx_snr found in packet. Setting tx delay:42
17:27:28 9570 [RadioIf] Can not send yet, busyRx
17:27:28 9570 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:28 9570 [RadioIf] rx_snr found in packet. Setting tx delay:0
17:27:28 9570 [RadioIf] Can not send yet, busyRx
17:27:28 9570 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:28 9570 [RadioIf] rx_snr found in packet. Setting tx delay:126
17:27:29 9570 [RadioIf] Can not send yet, busyRx
17:27:29 9570 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:29 9570 [RadioIf] rx_snr found in packet. Setting tx delay:0
17:27:29 9570 [RadioIf] Can not send yet, busyRx
17:27:29 9570 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:29 9570 [RadioIf] rx_snr found in packet. Setting tx delay:0
17:27:29 9570 [RadioIf] Can not send yet, busyRx
17:27:29 9570 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:29 9570 [RadioIf] rx_snr found in packet. Setting tx delay:0
17:27:29 9570 [RadioIf] Can not send yet, busyRx
17:27:29 9570 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:29 9570 [RadioIf] rx_snr found in packet. Setting tx delay:42
17:27:29 9570 [RadioIf] Can not send yet, busyRx
17:27:29 9570 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:29 9570 [RadioIf] rx_snr found in packet. Setting tx delay:0
17:27:29 9570 [RadioIf] Can not send yet, busyRx
17:27:29 9570 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:29 9570 [RadioIf] rx_snr found in packet. Setting tx delay:84
17:27:29 9571 [RadioIf] Can not send yet, busyRx
17:27:29 9571 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:29 9571 [RadioIf] rx_snr found in packet. Setting tx delay:126
17:27:29 9571 [RadioIf] Can not send yet, busyRx
17:27:29 9571 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:29 9571 [RadioIf] rx_snr found in packet. Setting tx delay:126
17:27:29 9571 [RadioIf] Can not send yet, busyRx
17:27:29 9571 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:29 9571 [RadioIf] rx_snr found in packet. Setting tx delay:0
17:27:29 9571 [RadioIf] Can not send yet, busyRx
17:27:29 9571 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:29 9571 [RadioIf] rx_snr found in packet. Setting tx delay:0
17:27:29 9571 [RadioIf] Can not send yet, busyRx
17:27:29 9571 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:29 9571 [RadioIf] rx_snr found in packet. Setting tx delay:126
17:27:29 9571 [RadioIf] Can not send yet, busyRx
17:27:29 9571 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:29 9571 [RadioIf] rx_snr found in packet. Setting tx delay:42
17:27:29 9571 [RadioIf] Can not send yet, busyRx
17:27:29 9571 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:29 9571 [RadioIf] rx_snr found in packet. Setting tx delay:126
17:27:29 9571 [RadioIf] Can not send yet, busyRx
17:27:29 9571 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:29 9571 [RadioIf] rx_snr found in packet. Setting tx delay:126
17:27:30 9571 [RadioIf] Can not send yet, busyRx
17:27:30 9571 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:30 9571 [RadioIf] rx_snr found in packet. Setting tx delay:0
17:27:30 9571 [RadioIf] Can not send yet, busyRx
17:27:30 9571 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:30 9571 [RadioIf] rx_snr found in packet. Setting tx delay:42
17:27:30 9571 [RadioIf] Can not send yet, busyRx
17:27:30 9571 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:30 9571 [RadioIf] rx_snr found in packet. Setting tx delay:126
17:27:30 9572 [RadioIf] Can not send yet, busyRx
17:27:30 9572 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:30 9572 [RadioIf] rx_snr found in packet. Setting tx delay:42
17:27:30 9572 [RadioIf] Can not send yet, busyRx
17:27:30 9572 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:30 9572 [RadioIf] rx_snr found in packet. Setting tx delay:42
17:27:30 9572 [RadioIf] Can not send yet, busyRx
17:27:30 9572 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:30 9572 [RadioIf] rx_snr found in packet. Setting tx delay:84
17:27:30 9572 [RadioIf] Can not send yet, busyRx
17:27:30 9572 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:30 9572 [RadioIf] rx_snr found in packet. Setting tx delay:84
17:27:30 9572 [RadioIf] Can not send yet, busyRx
17:27:30 9572 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:30 9572 [RadioIf] rx_snr found in packet. Setting tx delay:42
17:27:30 9572 [RadioIf] Can not send yet, busyRx
17:27:30 9572 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:30 9572 [RadioIf] rx_snr found in packet. Setting tx delay:0
17:27:30 9572 [RadioIf] Can not send yet, busyRx
17:27:30 9572 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:30 9572 [RadioIf] rx_snr found in packet. Setting tx delay:0
17:27:30 9572 [RadioIf] Can not send yet, busyRx
17:27:30 9572 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:30 9572 [RadioIf] rx_snr found in packet. Setting tx delay:84
17:27:30 9572 [RadioIf] Can not send yet, busyRx
17:27:30 9572 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:30 9572 [RadioIf] rx_snr found in packet. Setting tx delay:84
17:27:30 9572 [RadioIf] Can not send yet, busyRx
17:27:30 9572 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:30 9572 [RadioIf] rx_snr found in packet. Setting tx delay:42
17:27:30 9572 [RadioIf] Can not send yet, busyRx
17:27:30 9572 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:30 9572 [RadioIf] rx_snr found in packet. Setting tx delay:84
17:27:31 9572 [RadioIf] Can not send yet, busyRx
17:27:31 9572 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:31 9572 [RadioIf] rx_snr found in packet. Setting tx delay:42
17:27:31 9572 [RadioIf] Can not send yet, busyRx
17:27:31 9572 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:31 9572 [RadioIf] rx_snr found in packet. Setting tx delay:84
17:27:31 9572 [RadioIf] (bw=125, sf=12, cr=4/8) packet symLen=32 ms, payloadSize=44, time 3743 ms
17:27:31 9572 [RadioIf] Lora RX (id=0x3abcaae9 Fr0x0c To0xff, WantAck0, HopLim3 Ch0x2a encrypted rxSNR=-16.75 rxRSSI=1.84136)
17:27:31 9572 [RadioIf] AirTime - Packet received : 3743ms
17:27:31 9572 [Router] Add packet record (id=0x3abcaae9 Fr0x0c To0xff, WantAck0, HopLim3 Ch0x2a encrypted rxSNR=-16.75 rxRSSI=1.84136)
17:27:31 9572 [Router] Using channel 0 (hash 0x2a)
17:27:31 9572 [Router] Expanding short PSK #0
17:27:31 9572 [Router] Using AES0 key!
17:27:31 9572 [Router] decoded message (id=0x3abcaae9 Fr0x0c To0xff, WantAck0, HopLim3 Ch0x0 Portnum=67 rxtime=1666632451 rxSNR=-16.75 rxRSSI=1.84136)
17:27:31 9572 [Router] handleReceived(REMOTE) (id=0x3abcaae9 Fr0x0c To0xff, WantAck0, HopLim3 Ch0x0 Portnum=67 rxtime=1666632451 rxSNR=-16.75 rxRSSI=1.84136)
17:27:31 9572 [Router] Module 'DeviceTelemetry' wantsPacket=1
17:27:31 9572 [Router] Received DeviceTelemetry from=0xf246a50c, id=0x3abcaae9, portnum=67, payloadlen=24
17:27:31 9572 [Router] (Received from Cmp): air_util_tx=3.065583, channel_utilization=7.276667, battery_level=95, voltage=4.104000
17:27:31 9573 [Router] updateTelemetry REMOTE node=0xf246a50c 
17:27:31 9573 [Router] Node status update: 2 online, 4 total
17:27:31 9573 [Router] Module 'DeviceTelemetry' considered
17:27:31 9573 [Router] Module 'EnvironmentTelemetry' wantsPacket=1
17:27:31 9573 [Router] Received EnvironmentTelemetry from=0xf246a50c, id=0x3abcaae9, portnum=67, payloadlen=24
17:27:31 9573 [Router] Module 'EnvironmentTelemetry' considered
17:27:31 9573 [Router] Module 'routing' wantsPacket=1
17:27:31 9573 [Router] Received routing from=0xf246a50c, id=0x3abcaae9, portnum=67, payloadlen=24
17:27:31 9573 [Router] Routing sniffing (id=0x3abcaae9 Fr0x0c To0xff, WantAck0, HopLim3 Ch0x0 Portnum=67 rxtime=1666632451 rxSNR=-16.75 rxRSSI=1.84136)
17:27:31 9573 [Router] Rebroadcasting received floodmsg to neighbors (id=0x3abcaae9 Fr0x0c To0xff, WantAck0, HopLim3 Ch0x0 Portnum=67 rxtime=1666632451 rxSNR=-16.75 rxRSSI=1.84136)
17:27:31 9573 [Router] Should encrypt MQTT?: 1
17:27:31 9573 [Router] Expanding short PSK #0
17:27:31 9573 [Router] Using AES0 key!
17:27:31 9573 [Router] enqueuing for send (id=0x3abcaae9 Fr0x0c To0xff, WantAck0, HopLim2 Ch0x2a encrypted rxtime=1666632451 rxSNR=-16.75 rxRSSI=1.84136)
17:27:31 9573 [Router] txGood=92,rxGood=105,rxBad=0
17:27:31 9573 [Router] rx_snr found. hop_limit:2 rx_snr:-17.000000
17:27:31 9573 [Router] rx_snr found in packet. Setting tx delay:42
17:27:31 9573 [Router] FIXME-update-db Sniffing packet
17:27:31 9573 [Router] Delivering rx packet (id=0x3abcaae9 Fr0x0c To0xff, WantAck0, HopLim3 Ch0x0 Portnum=67 rxtime=1666632451 rxSNR=-16.75 rxRSSI=1.84136)
17:27:31 9573 [Router] Forwarding to phone (id=0x3abcaae9 Fr0x0c To0xff, WantAck0, HopLim3 Ch0x0 Portnum=67 rxtime=1666632451 rxSNR=-16.75 rxRSSI=1.84136)
17:27:31 9573 [Router] Update DB node 0xf246a50c, rx_time=1666632451
17:27:31 9573 [Router] Module 'routing' considered
17:27:31 9573 Telling client we have new packets 210
17:27:31 9573 [RadioIf] Starting low level send (id=0x3abcaae8 Fr0x0c To0xff, WantAck0, HopLim2 Ch0x2a encrypted rxtime=1666632445 rxSNR=-17 rxRSSI=1.84136 priority=64)
17:27:31 9573 [RadioIf] (bw=125, sf=12, cr=4/8) packet symLen=32 ms, payloadSize=56, time 4366 ms
17:27:31 9573 [RadioIf] AirTime - Packet transmitted : 4366ms
17:27:31 9573 [StreamAPI] getFromRadio=STATE_SEND_PACKETS
17:27:31 9573 [StreamAPI] phone downloaded packet (id=0x3abcaae9 Fr0x0c To0xff, WantAck0, HopLim3 Ch0x0 Portnum=67 rxtime=1666632451 rxSNR=-16.75 rxRSSI=1.84136)
17:27:31 9573 [StreamAPI] encoding toPhone packet to phone variant=2, 70 bytes
17:27:38 9580 [RadioIf] Completed sending (id=0x3abcaae8 Fr0x0c To0xff, WantAck0, HopLim2 Ch0x2a encrypted rxtime=1666632445 rxSNR=-17 rxRSSI=1.84136 priority=64)
17:27:38 9580 [RadioIf] Starting low level send (id=0x3abcaae9 Fr0x0c To0xff, WantAck0, HopLim2 Ch0x2a encrypted rxtime=1666632451 rxSNR=-16.75 rxRSSI=1.84136 priority=64)
17:27:38 9580 [RadioIf] (bw=125, sf=12, cr=4/8) packet symLen=32 ms, payloadSize=44, time 3743 ms
17:27:38 9580 [RadioIf] AirTime - Packet transmitted : 3743ms
17:27:41 9583 [PositionModule] Channel utilization is >25 percent. Skipping this opportunity to send.
17:27:43 9585 [Power] Battery: usbPower=1, isCharging=0, batMv=4156, batPct=100
17:27:44 9586 [RadioIf] Completed sending (id=0x3abcaae9 Fr0x0c To0xff, WantAck0, HopLim2 Ch0x2a encrypted rxtime=1666632451 rxSNR=-16.75 rxRSSI=1.84136 priority=64)
17:27:46 9588 [PositionModule] Channel utilization is >25 percent. Skipping this opportunity to send.
17:27:51 9593 [PositionModule] Channel utilization is >25 percent. Skipping this opportunity to send.

I also experience similar problems with both tlora v2-1-1.6 and tbeam-m8n-sx1262.
Both devices ping without loss, but timeout 50% of the time when called from CLI.

Thanks for confirmation. Do you also experience Wi-fi disconnects or IP connectivity loss after a few hours of connection time?

no I don’t. So this seems like a different problem. I’ll monitor the conected nodes a bit more over the next days.

Still no disconnect. We are having experiencing different bugs.

Hello,
Some updates about the Wi-fi dropping issue:

  • The problem seems to be somehow related to these two commands:
meshtastic --ch-set name HAMradio-2 --ch-index 0
meshtastic --ch-set id 0 --ch-index 0
  • If I only activate the wi-fi client from the CLI, I get no Wi-fi droppings (running for 20 hours at least…)
  • When the problem happens and the Wi-fi disconnects, the “meshtastic --noproto” debug output looks frozen, there is no output untill I press the reset button. The screen looks fine and reacts on pressing the button. A reset is needed for the wi-fi to reconnect.

Any thoughts?
Thanks.

One of our main firmware devs @caveman99 has been testing this for a while

With the ESP32 he has been averaging about:
7 to 9 ms and intermittent connection losses.
about 20% packet loss.

Here are the results for the newly added rak ethernet adaptor, so the wifi is not real reliable.

— ping statistics —
9073 packets transmitted, 9014 received, +18 errors, 0.650281% packet loss, time 9089459ms
rtt min/avg/max/mdev = 1.100/4.971/1046.563/15.920 ms, pipe 4

I can live with some packet loss, I know the ESP32 is not that great. But the big issue is the wi-fi disconnecting and never reconnecting back. And it looks like it’s related to one of the two commands I ran. I am trying to replace the --set-ham with --ch-set psk none for starters, will see what to do next…

Related to ping statistics, this is my tbeam connected as wi-fi client (very good signal):
— 192.168.1.134 ping statistics —
550 packets transmitted, 550 received, 0% packet loss, time 549624ms
rtt min/avg/max/mdev = 1.915/2.714/16.489/1.398 ms

Regards