DEBUG | 22:56:49 451 [RadioIf] Lora RX (id=0x9de7b832 fr=0xceb86766 to=0x57f42a69, WantAck=1, HopLim=7 Ch=0x8 encrypted len=22 rxSNR=5.75 rxRSSI=-77 hopStart=7) DEBUG | 22:56:49 451 [RadioIf] Packet RX: 395ms DEBUG | 22:56:49 451 [Router] Add packet record (id=0x9de7b832 fr=0xceb86766 to=0x57f42a69, WantAck=1, HopLim=7 Ch=0x8 encrypted len=22 rxSNR=5.75 rxRSSI=-77 hopStart=7) DEBUG | 22:56:49 451 [Router] Use channel 0 (hash 0x8) DEBUG | 22:56:49 451 [Router] Expand short PSK #1 DEBUG | 22:56:49 451 [Router] Use AES128 key! DEBUG | 22:56:49 451 [Router] decoded message (id=0x9de7b832 fr=0xceb86766 to=0x57f42a69, WantAck=1, HopLim=7 Ch=0x0 Portnum=70 WANTRESP rxtime=1738067209 rxSNR=5.75 rxRSSI=-77 hopStart=7) DEBUG | 22:56:49 451 [Router] handleReceived(REMOTE) (id=0x9de7b832 fr=0xceb86766 to=0x57f42a69, WantAck=1, HopLim=7 Ch=0x0 Portnum=70 WANTRESP rxtime=1738067209 rxSNR=5.75 rxRSSI=-77 hopStart=7) DEBUG | 22:56:49 451 [Router] Module 'traceroute' wantsPacket=1 INFO | 22:56:49 451 [Router] Received traceroute from=0xceb86766, id=0x9de7b832, portnum=70, payloadlen=0 INFO | 22:56:49 451 [Router] Route traced:0xceb86766 --> 0x6c3d5c6f (5.75dB) --> ... DEBUG | 22:56:49 451 [Router] Module 'traceroute' considered DEBUG | 22:56:49 451 [Router] Module 'neighborinfo' wantsPacket=1 INFO | 22:56:49 451 [Router] Received neighborinfo from=0xceb86766, id=0x9de7b832, portnum=70, payloadlen=9 DEBUG | 22:56:49 451 [Router] Module 'neighborinfo' considered DEBUG | 22:56:49 451 [Router] Module 'routing' wantsPacket=1 INFO | 22:56:49 451 [Router] Received routing from=0xceb86766, id=0x9de7b832, portnum=70, payloadlen=9 DEBUG | 22:56:49 451 [Router] Routing sniffing (id=0x9de7b832 fr=0xceb86766 to=0x57f42a69, WantAck=1, HopLim=7 Ch=0x0 Portnum=70 WANTRESP rxtime=1738067209 rxSNR=5.75 rxRSSI=-77 hopStart=7) INFO | 22:56:49 451 [Router] Rebroadcast received floodmsg DEBUG | 22:56:49 451 [Router] Expand short PSK #1 DEBUG | 22:56:49 451 [Router] Use AES128 key! DEBUG | 22:56:49 451 [Router] enqueue for send (id=0x9de7b832 fr=0xceb86766 to=0x57f42a69, WantAck=1, HopLim=6 Ch=0x8 encrypted len=33 rxtime=1738067209 rxSNR=5.75 rxRSSI=-77 hopStart=7 priority=70) DEBUG | 22:56:49 451 [Router] txGood=20,txRelay=18,rxGood=64,rxBad=3 DEBUG | 22:56:49 451 [Router] rx_snr found. hop_limit:6 rx_snr:5.750000 DEBUG | 22:56:49 451 [Router] rx_snr found in packet. Setting tx delay:5005 DEBUG | 22:56:49 451 [Router] Module 'routing' considered DEBUG | 22:56:49 451 [Router] MQTT onSend - Publish DEBUG | 22:56:49 451 [Router] encrypted message DEBUG | 22:56:49 451 [Router] MQTT Publish msh/ANZ/SA/2/e/LongFast/!6c3d5c6f, 75 bytes DEBUG | 22:56:54 456 [RadioIf] Started Tx (id=0x9de7b832 fr=0xceb86766 to=0x57f42a69, WantAck=1, HopLim=6 Ch=0x8 encrypted len=33 rxtime=1738067209 rxSNR=5.75 rxRSSI=-77 hopStart=7 priority=70) DEBUG | 22:56:54 456 [RadioIf] Packet TX: 477ms DEBUG | 22:56:54 456 [RadioIf] 0 packets remain in the TX queue DEBUG | 22:56:55 456 [RadioIf] Completed sending (id=0x9de7b832 fr=0xceb86766 to=0x57f42a69, WantAck=1, HopLim=6 Ch=0x8 encrypted len=33 rxtime=1738067209 rxSNR=5.75 rxRSSI=-77 hopStart=7 priority=70) DEBUG | 22:56:56 457 [RadioIf] Lora RX (id=0x827fe923 fr=0x57f42a69 to=0xceb86766, WantAck=1, HopLim=3 Ch=0x8 encrypted len=46 rxSNR=-1.25 rxRSSI=-101 hopStart=3) DEBUG | 22:56:56 457 [RadioIf] Packet RX: 575ms DEBUG | 22:56:56 457 [Router] Add packet record (id=0x827fe923 fr=0x57f42a69 to=0xceb86766, WantAck=1, HopLim=3 Ch=0x8 encrypted len=46 rxSNR=-1.25 rxRSSI=-101 hopStart=3) DEBUG | 22:56:56 457 [Router] Use channel 0 (hash 0x8) DEBUG | 22:56:56 457 [Router] Expand short PSK #1 DEBUG | 22:56:56 457 [Router] Use AES128 key! DEBUG | 22:56:56 457 [Router] decoded message (id=0x827fe923 fr=0x57f42a69 to=0xceb86766, WantAck=1, HopLim=3 Ch=0x0 Portnum=70 requestId=9de7b832 rxtime=1738067216 rxSNR=-1.25 rxRSSI=-101 hopStart=3) DEBUG | 22:56:56 457 [Router] handleReceived(REMOTE) (id=0x827fe923 fr=0x57f42a69 to=0xceb86766, WantAck=1, HopLim=3 Ch=0x0 Portnum=70 requestId=9de7b832 rxtime=1738067216 rxSNR=-1.25 rxRSSI=-101 hopStart=3) DEBUG | 22:56:56 457 [Router] Module 'traceroute' wantsPacket=1 INFO | 22:56:56 457 [Router] Received traceroute from=0x57f42a69, id=0x827fe923, portnum=70, payloadlen=19 INFO | 22:56:56 457 [Router] Route traced:0xceb86766 --> 0x6c3d5c6f (5.75dB) --> 0x57f42a69 (-14.00dB)...(-1.25dB) 0x6c3d5c6f <-- 0x57f42a69 DEBUG | 22:56:56 457 [Router] Module 'traceroute' considered DEBUG | 22:56:56 457 [Router] Module 'neighborinfo' wantsPacket=1 INFO | 22:56:56 457 [Router] Received neighborinfo from=0x57f42a69, id=0x827fe923, portnum=70, payloadlen=37 DEBUG | 22:56:56 457 [Router] Module 'neighborinfo' considered DEBUG | 22:56:56 457 [Router] Module 'routing' wantsPacket=1 INFO | 22:56:56 457 [Router] Received routing from=0x57f42a69, id=0x827fe923, portnum=70, payloadlen=37 DEBUG | 22:56:56 457 [Router] Routing sniffing (id=0x827fe923 fr=0x57f42a69 to=0xceb86766, WantAck=1, HopLim=3 Ch=0x0 Portnum=70 requestId=9de7b832 rxtime=1738067216 rxSNR=-1.25 rxRSSI=-101 hopStart=3) DEBUG | 22:56:56 457 [Router] Rxd an ACK/reply not for me, cancel rebroadcast DEBUG | 22:56:56 457 [Router] cancelSending id=0x9de7b832, removed=0 INFO | 22:56:56 457 [Router] Rebroadcast received floodmsg DEBUG | 22:56:56 457 [Router] Expand short PSK #1 DEBUG | 22:56:56 457 [Router] Use AES128 key! DEBUG | 22:56:56 457 [Router] enqueue for send (id=0x827fe923 fr=0x57f42a69 to=0xceb86766, WantAck=1, HopLim=2 Ch=0x8 encrypted len=64 rxtime=1738067216 rxSNR=-1.25 rxRSSI=-101 hopStart=3 priority=80) DEBUG | 22:56:56 457 [Router] txGood=21,txRelay=19,rxGood=65,rxBad=3 DEBUG | 22:56:56 457 [Router] rx_snr found. hop_limit:2 rx_snr:-1.250000 DEBUG | 22:56:56 457 [Router] rx_snr found in packet. Setting tx delay:1694 DEBUG | 22:56:56 457 [Router] Module 'routing' considered DEBUG | 22:56:56 457 [Router] MQTT onSend - Publish DEBUG | 22:56:56 457 [Router] encrypted message DEBUG | 22:56:56 457 [Router] MQTT Publish msh/ANZ/SA/2/e/LongFast/!6c3d5c6f, 99 bytes DEBUG | 22:56:57 458 [RadioIf] Lora RX (id=0x827fe923 fr=0x57f42a69 to=0xceb86766, WantAck=1, HopLim=2 Ch=0x8 encrypted len=55 rxSNR=4.25 rxRSSI=-90 hopStart=3) DEBUG | 22:56:57 458 [RadioIf] Packet RX: 641ms DEBUG | 22:56:57 458 [RadioIf] rx_snr found. hop_limit:2 rx_snr:-1.250000 DEBUG | 22:56:57 458 [RadioIf] rx_snr found in packet. Setting tx delay:4389 DEBUG | 22:56:57 458 [Router] Found existing packet record for fr=0x57f42a69,to=0xceb86766,id=0x827fe923 DEBUG | 22:56:57 458 [Router] Add packet record (id=0x827fe923 fr=0x57f42a69 to=0xceb86766, WantAck=1, HopLim=2 Ch=0x8 encrypted len=55 rxSNR=4.25 rxRSSI=-90 hopStart=3) DEBUG | 22:56:57 458 [Router] Ignore dupe incoming msg (id=0x827fe923 fr=0x57f42a69 to=0xceb86766, WantAck=1, HopLim=2 Ch=0x8 encrypted len=55 rxSNR=4.25 rxRSSI=-90 hopStart=3) DEBUG | 22:56:57 458 [Router] Move existing queued packet to the late rebroadcast window 10934ms from now DEBUG | 22:56:57 458 [Router] Incoming msg will be filtered, from 0x57f42a69 DEBUG | 22:56:57 458 [Router] Use channel 0 (hash 0x8) DEBUG | 22:56:57 458 [Router] Expand short PSK #1 DEBUG | 22:56:57 458 [Router] Use AES128 key! DEBUG | 22:56:57 458 [Router] decoded message (id=0x827fe923 fr=0x57f42a69 to=0xceb86766, WantAck=1, HopLim=2 Ch=0x0 Portnum=70 requestId=9de7b832 rxtime=1738067217 rxSNR=4.25 rxRSSI=-90 hopStart=3) DEBUG | 22:56:57 458 [Router] handleReceived(REMOTE) (id=0x827fe923 fr=0x57f42a69 to=0xceb86766, WantAck=1, HopLim=2 Ch=0x0 Portnum=70 requestId=9de7b832 rxtime=1738067217 rxSNR=4.25 rxRSSI=-90 hopStart=3) DEBUG | 22:56:57 458 [Router] cancelSending id=0x827fe923, removed=1 DEBUG | 22:56:57 458 [Router] MQTT onSend - Publish DEBUG | 22:56:57 458 [Router] encrypted message DEBUG | 22:56:57 458 [Router] MQTT Publish msh/ANZ/SA/2/e/LongFast/!6c3d5c6f, 108 bytes DEBUG | 22:56:59 461 [RadioIf] Lora RX (id=0x6d30a634 fr=0xda635580 to=0xffffffff, WantAck=0, HopLim=0 Ch=0x8 encrypted len=45 rxSNR=-18.5 rxRSSI=-119 hopStart=7) DEBUG | 22:56:59 461 [RadioIf] Packet RX: 567ms DEBUG | 22:56:59 461 [Router] Add packet record (id=0x6d30a634 fr=0xda635580 to=0xffffffff, WantAck=0, HopLim=0 Ch=0x8 encrypted len=45 rxSNR=-18.5 rxRSSI=-119 hopStart=7) DEBUG | 22:56:59 461 [Router] Use channel 0 (hash 0x8) DEBUG | 22:56:59 461 [Router] Expand short PSK #1 DEBUG | 22:56:59 461 [Router] Use AES128 key! DEBUG | 22:56:59 461 [Router] decoded message (id=0x6d30a634 fr=0xda635580 to=0xffffffff, WantAck=0, HopLim=0 Ch=0x0 Portnum=3 rxtime=1738067219 rxSNR=-18.5 rxRSSI=-119 hopStart=7) DEBUG | 22:56:59 461 [Router] handleReceived(REMOTE) (id=0x6d30a634 fr=0xda635580 to=0xffffffff, WantAck=0, HopLim=0 Ch=0x0 Portnum=3 rxtime=1738067219 rxSNR=-18.5 rxRSSI=-119 hopStart=7) DEBUG | 22:56:59 461 [Router] Module 'position' wantsPacket=1 INFO | 22:56:59 461 [Router] Received position from=0xda635580, id=0x6d30a634, portnum=3, payloadlen=25 DEBUG | 22:56:59 461 [Router] POSITION node=da635580 l=25 lat=-351862784 lon=1384841216 msl=27 hae=0 geo=0 pdop=0 hdop=0 vdop=0 siv=0 fxq=0 fxt=0 pts=0 time=1738067201 DEBUG | 22:56:59 461 [Router] Ignore time from mesh because we have a GPS, RTC, or Phone/NTP time source in the past day INFO | 22:56:59 461 [Router] updatePosition REMOTE node=0xda635580 time=1738067201 lat=-351862784 lon=1384841216 DEBUG | 22:56:59 461 [Router] Node status update: 40 online, 131 total DEBUG | 22:56:59 461 [Router] Module 'position' considered DEBUG | 22:56:59 461 [Router] Module 'neighborinfo' wantsPacket=1 INFO | 22:56:59 461 [Router] Received neighborinfo from=0xda635580, id=0x6d30a634, portnum=3, payloadlen=25 DEBUG | 22:56:59 461 [Router] Module 'neighborinfo' considered DEBUG | 22:56:59 461 [Router] Module 'routing' wantsPacket=1 INFO | 22:56:59 461 [Router] Received routing from=0xda635580, id=0x6d30a634, portnum=3, payloadlen=25 DEBUG | 22:56:59 461 [Router] Routing sniffing (id=0x6d30a634 fr=0xda635580 to=0xffffffff, WantAck=0, HopLim=0 Ch=0x0 Portnum=3 rxtime=1738067219 rxSNR=-18.5 rxRSSI=-119 hopStart=7) DEBUG | 22:56:59 461 [Router] Delivering rx packet (id=0x6d30a634 fr=0xda635580 to=0xffffffff, WantAck=0, HopLim=0 Ch=0x0 Portnum=3 rxtime=1738067219 rxSNR=-18.5 rxRSSI=-119 hopStart=7) DEBUG | 22:56:59 461 [Router] Update DB node 0xda635580, rx_time=1738067219 DEBUG | 22:56:59 461 [Router] Forwarding to phone (id=0x6d30a634 fr=0xda635580 to=0xffffffff, WantAck=0, HopLim=0 Ch=0x0 Portnum=3 rxtime=1738067219 rxSNR=-18.5 rxRSSI=-119 hopStart=7) DEBUG | 22:56:59 461 [Router] Module 'routing' considered DEBUG | 22:56:59 461 [Router] MQTT onSend - Publish DEBUG | 22:56:59 461 [Router] encrypted message DEBUG | 22:56:59 461 [Router] MQTT Publish msh/ANZ/SA/2/e/LongFast/!6c3d5c6f, 94 bytes DEBUG | 22:57:32 494 [RadioIf] Lora RX (id=0x502bd987 fr=0x2b2e7610 to=0xffffffff, WantAck=0, HopLim=1 Ch=0x8 encrypted len=50 rxSNR=-15.75 rxRSSI=-117 hopStart=3) DEBUG | 22:57:32 494 [RadioIf] Packet RX: 608ms DEBUG | 22:57:32 494 [Router] Add packet record (id=0x502bd987 fr=0x2b2e7610 to=0xffffffff, WantAck=0, HopLim=1 Ch=0x8 encrypted len=50 rxSNR=-15.75 rxRSSI=-117 hopStart=3) DEBUG | 22:57:32 494 [Router] Use channel 0 (hash 0x8) DEBUG | 22:57:32 494 [Router] Expand short PSK #1 DEBUG | 22:57:32 494 [Router] Use AES128 key! DEBUG | 22:57:32 494 [Router] decoded message (id=0x502bd987 fr=0x2b2e7610 to=0xffffffff, WantAck=0, HopLim=1 Ch=0x0 Portnum=3 rxtime=1738067252 rxSNR=-15.75 rxRSSI=-117 hopStart=3) DEBUG | 22:57:32 494 [Router] handleReceived(REMOTE) (id=0x502bd987 fr=0x2b2e7610 to=0xffffffff, WantAck=0, HopLim=1 Ch=0x0 Portnum=3 rxtime=1738067252 rxSNR=-15.75 rxRSSI=-117 hopStart=3) DEBUG | 22:57:32 494 [Router] Module 'position' wantsPacket=1 INFO | 22:57:32 494 [Router] Received position from=0x2b2e7610, id=0x502bd987, portnum=3, payloadlen=28 DEBUG | 22:57:32 494 [Router] POSITION node=2b2e7610 l=28 lat=-349437952 lon=1385955328 msl=0 hae=0 geo=0 pdop=0 hdop=0 vdop=0 siv=0 fxq=0 fxt=0 pts=1737943028 time=1738067261 DEBUG | 22:57:32 494 [Router] Ignore time from mesh because we have a GPS, RTC, or Phone/NTP time source in the past day INFO | 22:57:32 494 [Router] updatePosition REMOTE node=0x2b2e7610 time=1738067261 lat=-349437952 lon=1385955328 DEBUG | 22:57:32 494 [Router] Node status update: 40 online, 131 total DEBUG | 22:57:32 494 [Router] Module 'position' considered DEBUG | 22:57:32 494 [Router] Module 'neighborinfo' wantsPacket=1 INFO | 22:57:32 494 [Router] Received neighborinfo from=0x2b2e7610, id=0x502bd987, portnum=3, payloadlen=28 DEBUG | 22:57:32 494 [Router] Module 'neighborinfo' considered DEBUG | 22:57:32 494 [Router] Module 'routing' wantsPacket=1 INFO | 22:57:32 494 [Router] Received routing from=0x2b2e7610, id=0x502bd987, portnum=3, payloadlen=28 DEBUG | 22:57:32 494 [Router] Routing sniffing (id=0x502bd987 fr=0x2b2e7610 to=0xffffffff, WantAck=0, HopLim=1 Ch=0x0 Portnum=3 rxtime=1738067252 rxSNR=-15.75 rxRSSI=-117 hopStart=3) INFO | 22:57:32 494 [Router] Rebroadcast received floodmsg DEBUG | 22:57:32 494 [Router] Expand short PSK #1 DEBUG | 22:57:32 494 [Router] Use AES128 key! DEBUG | 22:57:32 494 [Router] enqueue for send (id=0x502bd987 fr=0x2b2e7610 to=0xffffffff, WantAck=0, HopLim=0 Ch=0x8 encrypted len=50 rxtime=1738067252 rxSNR=-15.75 rxRSSI=-117 hopStart=3 priority=64) DEBUG | 22:57:32 494 [Router] txGood=21,txRelay=19,rxGood=68,rxBad=3 DEBUG | 22:57:32 494 [Router] rx_snr found. hop_limit:0 rx_snr:-15.750000 DEBUG | 22:57:32 494 [Router] rx_snr found in packet. Setting tx delay:10780 DEBUG | 22:57:32 494 [Router] Delivering rx packet (id=0x502bd987 fr=0x2b2e7610 to=0xffffffff, WantAck=0, HopLim=1 Ch=0x0 Portnum=3 rxtime=1738067252 rxSNR=-15.75 rxRSSI=-117 hopStart=3) DEBUG | 22:57:32 494 [Router] Update DB node 0x2b2e7610, rx_time=1738067252 DEBUG | 22:57:32 494 [Router] Forwarding to phone (id=0x502bd987 fr=0x2b2e7610 to=0xffffffff, WantAck=0, HopLim=1 Ch=0x0 Portnum=3 rxtime=1738067252 rxSNR=-15.75 rxRSSI=-117 hopStart=3) DEBUG | 22:57:32 494 [Router] Module 'routing' considered DEBUG | 22:57:32 494 [Router] MQTT onSend - Publish DEBUG | 22:57:32 494 [Router] encrypted message DEBUG | 22:57:32 494 [Router] MQTT Publish msh/ANZ/SA/2/e/LongFast/!6c3d5c6f, 101 bytes DEBUG | 22:57:43 505 [RadioIf] Started Tx (id=0x502bd987 fr=0x2b2e7610 to=0xffffffff, WantAck=0, HopLim=0 Ch=0x8 encrypted len=50 rxtime=1738067252 rxSNR=-15.75 rxRSSI=-117 hopStart=3 priority=64) DEBUG | 22:57:43 505 [RadioIf] Packet TX: 608ms DEBUG | 22:57:43 505 [RadioIf] 0 packets remain in the TX queue