Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

[Bug]: Firmware 2.5 Alpha - Admin channel "NO_Response" #4708

Closed
thatSFguy opened this issue Sep 14, 2024 · 22 comments
Closed

[Bug]: Firmware 2.5 Alpha - Admin channel "NO_Response" #4708

thatSFguy opened this issue Sep 14, 2024 · 22 comments
Labels
bug Something isn't working

Comments

@thatSFguy
Copy link

thatSFguy commented Sep 14, 2024 •
edited
Loading

Category

Other

Hardware

T-Lora v2 1.6, Rak4631

Firmware Version

2.5.0.9ac0e26

Description

Installed the firmware (2.5.0.9ac0e26) on both Tlora and RAK devices. Admin channels were already configured on the devices.

  1. Tested via Android the remote configuration from Tlora to RAK, RAK to Tlora, Tlora to Tlora. Get the "NO RESPONSE" error.
  2. Utilized a portuino (firmware 2.4) to attempt CLI configuration of 2.5 nodes and received the "NO Response" error
  3. Regression tested admin configuration from 2.5 node to the portunino 2.4 node and that worked

Relevant log output

FAILED Admin request from Android device on Tlora to RAK
`INFO | 18:33:12 767 [DeviceTelemetryModule] (Sending): air_util_tx=0.083222, channel_utilization=0.931667, battery_level=101, voltage=4.229000, uptime=767

DEBUG | 18:33:12 767 [DeviceTelemetryModule] Partially randomized packet id 1977415757

DEBUG | 18:33:12 767 [DeviceTelemetryModule] updateTelemetry LOCAL

DEBUG | 18:33:12 767 [DeviceTelemetryModule] Node status update: 7 online, 8 total

INFO | 18:33:12 767 [DeviceTelemetryModule] Sending packet to phone

INFO | 18:33:12 767 Telling client we have new packets 27

INFO | 18:33:12 767 BLE notify fromNum

INFO | 18:33:12 767 getFromRadio=STATE_SEND_PACKETS

DEBUG | 18:33:12 767 phone downloaded packet (id=0x75dcf84d fr=0xa4 to=0xff, WantAck=0, HopLim=7 Ch=0x0 Portnum=67 rxtime=1726338792 priority=10)

INFO | 18:33:13 768 To Radio onwrite

DEBUG | 18:33:13 768 PACKET FROM PHONE (id=0xa3679966 fr=0x00 to=0x08, WantAck=1, HopLim=7 Ch=0x3 Portnum=6 WANTRESP priority=70)

DEBUG | 18:33:13 768 (bw=250, sf=11, cr=4/5) packet symLen=8 ms, payloadSize=24, time 411 ms

DEBUG | 18:33:13 768 Setting next retransmission in 7940 msecs: (id=0xa3679966 fr=0x00 to=0x08, WantAck=1, HopLim=7 Ch=0x3 Portnum=6 WANTRESP rxtime=1726338793 priority=70)

DEBUG | 18:33:13 768 Add packet record (id=0xa3679966 fr=0x00 to=0x08, WantAck=1, HopLim=7 Ch=0x3 Portnum=6 WANTRESP rxtime=1726338793 priority=70)

DEBUG | 18:33:13 768 Using PKI!

INFO | 18:33:13 768 Random nonce value: 10...............

DEBUG | 18:33:13 768 DH Output: : 7b 7d 4b 6b b9 b8 68 5.........................

DEBUG | 18:33:14 768 Attempting encrypt using nonce: : 66 99 67 a3 ............................

DEBUG | 18:33:14 768 Attempting encrypt using shared_key: : 97 f8 4b cb 53 df 50 ...............................

DEBUG | 18:33:14 768 enqueuing for send (id=0xa3679966 fr=0xa4 to=0x08, WantAck=1, HopLim=7 Ch=0x0 encrypted rxtime=1726338793 hopStart=7 priority=70)

DEBUG | 18:33:14 768 txGood=4,rxGood=26,rxBad=0

DEBUG | 18:33:14 768 [RadioIf] Starting low level send (id=0xa3679966 fr=0xa4 to=0x08, WantAck=1, HopLim=7 Ch=0x0 encrypted rxtime=1726338793 hopStart=7 priority=70)

DEBUG | 18:33:14 768 [RadioIf] (bw=250, sf=11, cr=4/5) packet symLen=8 ms, payloadSize=38, time 518 ms

DEBUG | 18:33:14 768 [RadioIf] AirTime - Packet transmitted : 518ms

INFO | 18:33:14 768 Telling client we have new packets 28

INFO | 18:33:14 768 BLE notify fromNum

INFO | 18:33:14 768 getFromRadio=STATE_SEND_PACKETS

DEBUG | 18:33:14 769 [RadioIf] Completed sending (id=0xa3679966 fr=0xa4 to=0x08, WantAck=1, HopLim=7 Ch=0x0 encrypted rxtime=1726338793 hopStart=7 priority=70)

DEBUG | 18:33:15 769 [RadioIf] (bw=250, sf=11, cr=4/5) packet symLen=8 ms, payloadSize=38, time 518 ms

DEBUG | 18:33:15 769 [RadioIf] Lora RX (id=0xa3679966 fr=0xa4 to=0x08, WantAck=1, HopLim=6 Ch=0x0 encrypted rxSNR=10.25 rxRSSI=-67 hopStart=7)

DEBUG | 18:33:15 769 [RadioIf] AirTime - Packet received : 518ms

DEBUG | 18:33:15 769 [Router] Rx someone rebroadcasting for us (id=0xa3679966 fr=0xa4 to=0x08, WantAck=1, HopLim=6 Ch=0x0 encrypted rxSNR=10.25 rxRSSI=-67 hopStart=7)

DEBUG | 18:33:15 769 [Router] generating implicit ack

DEBUG | 18:33:15 769 [Router] Partially randomized packet id 4274809934

DEBUG | 18:33:15 770 [Router] Enqueued local (id=0xfecc6c4e fr=0xa4 to=0xa4, WantAck=0, HopLim=7 Ch=0x3 Portnum=5 requestId=a3679966 rxtime=1726338795 priority=120)

DEBUG | 18:33:15 770 [Router] Found existing packet record for fr=0x25c0dba4,to=0xb2982108,id=0xa3679966

DEBUG | 18:33:15 770 [Router] Found existing packet record for fr=0x25c0dba4,to=0xb2982108,id=0xa3679966

DEBUG | 18:33:15 770 [Router] Add packet record (id=0xa3679966 fr=0xa4 to=0x08, WantAck=1, HopLim=6 Ch=0x0 encrypted rxSNR=10.25 rxRSSI=-67 hopStart=7)

DEBUG | 18:33:15 770 [Router] Ignoring incoming msg we've already seen (id=0xa3679966 fr=0xa4 to=0x08, WantAck=1, HopLim=6 Ch=0x0 encrypted rxSNR=10.25 rxRSSI=-67 hopStart=7)

DEBUG | 18:33:15 770 [Router] cancelSending id=0xa3679966, removed=0

DEBUG | 18:33:15 770 [Router] Incoming message was filtered from 0x25c0dba4

DEBUG | 18:33:15 770 [Router] Rx someone rebroadcasting for us (id=0xfecc6c4e fr=0xa4 to=0xa4, WantAck=0, HopLim=7 Ch=0x3 Portnum=5 requestId=a3679966 rxtime=1726338795 priority=120)

DEBUG | 18:33:15 770 [Router] didn't find pending packet

DEBUG | 18:33:15 770 [Router] Add packet record (id=0xfecc6c4e fr=0xa4 to=0xa4, WantAck=0, HopLim=7 Ch=0x3 Portnum=5 requestId=a3679966 rxtime=1726338795 priority=120)

DEBUG | 18:33:15 770 [Router] handleReceived(REMOTE) (id=0xfecc6c4e fr=0xa4 to=0xa4, WantAck=0, HopLim=7 Ch=0x3 Portnum=5 requestId=a3679966 rxtime=1726338795 priority=120)

DEBUG | 18:33:15 770 [Router] Module 'routing' wantsPacket=1

INFO | 18:33:15 770 [Router] Received routing from=0x25c0dba4, id=0xfecc6c4e, portnum=5, payloadlen=2

DEBUG | 18:33:15 770 [Router] Routing sniffing (id=0xfecc6c4e fr=0xa4 to=0xa4, WantAck=0, HopLim=7 Ch=0x3 Portnum=5 requestId=a3679966 rxtime=1726338795 priority=120)

DEBUG | 18:33:15 770 [Router] Received an ack for 0xa3679966, stopping retransmissions

DEBUG | 18:33:15 770 [Router] Delivering rx packet (id=0xfecc6c4e fr=0xa4 to=0xa4, WantAck=0, HopLim=7 Ch=0x3 Portnum=5 requestId=a3679966 rxtime=1726338795 priority=120)

DEBUG | 18:33:15 770 [Router] Update DB node 0x25c0dba4, rx_time=1726338795

DEBUG | 18:33:15 770 [Router] Forwarding to phone (id=0xfecc6c4e fr=0xa4 to=0xa4, WantAck=0, HopLim=7 Ch=0x3 Portnum=5 requestId=a3679966 rxtime=1726338795 priority=120)

DEBUG | 18:33:15 770 [Router] Module 'routing' considered

INFO | 18:33:15 770 Telling client we have new packets 29

INFO | 18:33:15 770 BLE notify fromNum

INFO | 18:33:15 770 getFromRadio=STATE_SEND_PACKETS

DEBUG | 18:33:15 770 phone downloaded packet (id=0xfecc6c4e fr=0xa4 to=0xa4, WantAck=0, HopLim=7 Ch=0x3 Portnum=5 requestId=a3679966 rxtime=1726338795 priority=120)

DEBUG | 18:33:15 770 [RadioIf] (bw=250, sf=11, cr=4/5) packet symLen=8 ms, payloadSize=29, time 452 ms

DEBUG | 18:33:15 770 [RadioIf] Lora RX (id=0x29dd4a23 fr=0x08 to=0xa4, WantAck=0, HopLim=2 Ch=0x8 encrypted rxSNR=14 rxRSSI=-36 hopStart=2)

DEBUG | 18:33:15 770 [RadioIf] AirTime - Packet received : 452ms

DEBUG | 18:33:15 770 [Router] Add packet record (id=0x29dd4a23 fr=0x08 to=0xa4, WantAck=0, HopLim=2 Ch=0x8 encrypted rxSNR=14 rxRSSI=-36 hopStart=2)

DEBUG | 18:33:15 770 [Router] Using channel 1 (hash 0x8)

DEBUG | 18:33:15 770 [Router] Expanding short PSK #1

DEBUG | 18:33:15 770 [Router] Using AES128 key!

DEBUG | 18:33:16 770 [Router] decoded message (id=0x29dd4a23 fr=0x08 to=0xa4, WantAck=0, HopLim=2 Ch=0x1 Portnum=5 requestId=a3679966 rxtime=1726338795 rxSNR=14 rxRSSI=-36 hopStart=2)

DEBUG | 18:33:16 770 [Router] handleReceived(REMOTE) (id=0x29dd4a23 fr=0x08 to=0xa4, WantAck=0, HopLim=2 Ch=0x1 Portnum=5 requestId=a3679966 rxtime=1726338795 rxSNR=14 rxRSSI=-36 hopStart=

DEBUG | 18:33:16 770 [Router] Module 'routing' wantsPacket=1

INFO | 18:33:16 770 [Router] Received routing from=0xb2982108, id=0x29dd4a23, portnum=5, payloadlen=2

DEBUG | 18:33:16 770 [Router] Routing sniffing (id=0x29dd4a23 fr=0x08 to=0xa4, WantAck=0, HopLim=2 Ch=0x1 Portnum=5 requestId=a3679966 rxtime=1726338795 rxSNR=14 rxRSSI=-36 hopStart=2)

DEBUG | 18:33:16 770 [Router] Received a nak for 0xa3679966, stopping retransmissions

DEBUG | 18:33:16 770 [Router] Delivering rx packet (id=0x29dd4a23 fr=0x08 to=0xa4, WantAck=0, HopLim=2 Ch=0x1 Portnum=5 requestId=a3679966 rxtime=1726338795 rxSNR=14 rxRSSI=-36 hopStart=2)

DEBUG | 18:33:16 770 [Router] Update DB node 0xb2982108, rx_time=1726338795

DEBUG | 18:33:16 770 [Router] Forwarding to phone (id=0x29dd4a23 fr=0x08 to=0xa4, WantAck=0, HopLim=2 Ch=0x1 Portnum=5 requestId=a3679966 rxtime=1726338795 rxSNR=14 rxRSSI=-36 hopStart=2)

DEBUG | 18:33:16 770 [Router] Module 'routing' considered

INFO | 18:33:16 770 Telling client we have new packets 30

INFO | 18:33:16 770 BLE notify fromNum

INFO | 18:33:16 770 getFromRadio=STATE_SEND_PACKETS

DEBUG | 18:33:16 770 phone downloaded packet (id=0x29dd4a23 fr=0x08 to=0xa4, WantAck=0, HopLim=2 Ch=0x1 Portnum=5 requestId=a3679966 rxtime=1726338795 rxSNR=14 rxRSSI=-36 hopStart

DEBUG | 18:33:16 771 [RadioIf] (bw=250, sf=11, cr=4/5) packet symLen=8 ms, payloadSize=27, time 436 ms

DEBUG | 18:33:16 771 [RadioIf] Lora RX (id=0x29dd4a23 fr=0x08 to=0xa4, WantAck=0, HopLim=1 Ch=0x8 encrypted rxSNR=10 rxRSSI=-68 hopStart=2)

DEBUG | 18:33:16 771 [RadioIf] AirTime - Packet received : 436ms

DEBUG | 18:33:16 771 [Router] Found existing packet record for fr=0xb2982108,to=0x25c0dba4,id=0x29dd4a23

DEBUG | 18:33:16 771 [Router] Found existing packet record for fr=0xb2982108,to=0x25c0dba4,id=0x29dd4a23

DEBUG | 18:33:16 771 [Router] Add packet record (id=0x29dd4a23 fr=0x08 to=0xa4, WantAck=0, HopLim=1 Ch=0x8 encrypted rxSNR=10 rxRSSI=-68 hopStart=2)

DEBUG | 18:33:16 771 [Router] Ignoring incoming msg we've already seen (id=0x29dd4a23 fr=0x08 to=0xa4, WantAck=0, HopLim=1 Ch=0x8 encrypted rxSNR=10 rxRSSI=-68 hopStart=2)

DEBUG | 18:33:16 771 [Router] cancelSending id=0x29dd4a23, removed=0

DEBUG | 18:33:16 771 [Router] Incoming message was filtered from 0xb2982108

DEBUG | 18:33:27 782 [Power] Battery: usbPower=1, isCharging=1, batMv=4229, batPct=100`
@thatSFguy thatSFguy added the bug Something isn't working label Sep 14, 2024
@caveman99
Copy link
Member

what version of the android app do you have? you need at least 2.4.5

@thatSFguy
Copy link
Author

I'm on 2.4.5 (Beta) via the app store.

@thatSFguy
Copy link
Author

Updated the bug and removed the DM issue, so the focus is only remote administration. The DM issue seems to be related an "unsupported crystal" on the TLora device. I'll open a separate bug for that.

@pyro2927
Copy link

I'm seeing the same issue on a Heltec v3 and Lilygo T-Deck. Firmware version 2.5.0.9ac0e26, accessing via the Python CLI. The Heltec v3 is on WiFi.

$ meshtastic --host 192.168.1.25 --dest '!bd4c2170' --get device  
Connected to radio
Requesting current config from remote node (this can take a while).
Error on response: NO_RESPONSE
Completed getting preferences

@jp-bennett
Copy link
Collaborator

An unintended consequence of all the 2.5 changes is that the legacy admin channel won't work at all between 2.5 devices. Using your public key as the admin key on the device you want to control is the way to go.

Controlling a 2.5 device from a 2.4 node might not work either, as the 2.4 node doesn't have the updated protobuf fields to handle the session key. I need to test that case out myself.

@pyro2927
Copy link

pyro2927 commented Sep 15, 2024 •
edited
Loading

Both of my devices are on 2.5, so I don't think that would be the issue. That said, I hadn't added the public key of my primary node as the admin key on the other. After doing that I run into a slightly different issue:

$ meshtastic --host 192.168.1.25 --dest '!bd4c2170' --get device
Connected to radio
Requesting current config from remote node (this can take a while).
Aborting due to: Timed out waiting for an acknowledgment

@jp-bennett
Copy link
Collaborator

@pyro2927 can you successfully send DMs between the two nodes? If not, you probably have a key mismatch from bouncing around your firmware versions. Use the Python client and --nodes to compare the actual public key to what the opposite device sees in its NodeDB, and remove the node from the nodeDB if it doesn't match.

@slawekgajzner
Copy link

Correct me if I'm wrong.

For the admin channel to work (not in legacy mode) the packet must also be encrypted (mp.pki_encrypted == true)

AdminModule.cpp:
if (!((mp.from == 0 && !config.security.is_managed) || messageIsResponse(r) ||
(strcasecmp(ch->settings.name, Channels::adminChannel) == 0 && config.security.admin_channel_enabled) ||
(mp.pki_encrypted && memcmp(mp.public_key.bytes, config.security.admin_key[0].bytes, 32) == 0))) {
LOG_INFO("Ignoring admin payload %i\n", r->which_payload_variant);
return handled; }

For pki_encrypted to be true, the message must arrive on channel 0

Router.cpp (perhapsDecode)
if (p->channel == 0 && p->to == nodeDB->getNodeNum() && p->to > 0 && p->to != NODENUM_BROADCAST && nodeDB->getMeshNode(p->from) != nullptr && nodeDB->getMeshNode(p->from)->user.public _key.size > 0 &&
nodeDB->getMeshNode(p->to)->user.public_key.size > 0 && rawSize > 12)
{
LOG_DEBUG("Attempting PKI decryption\n");

if (crypto->decryptCurve25519(p->from, p->id, rawSize, ScratchEncrypted, bytes)) {
LOG_INFO("PKI Decryption worked!\n");
memset(&p->decoded, 0, sizeof(p->decoded));
rawSize -= 12;
if (pb_decode_from_bytes(bytes, rawSize, &meshtastic_Data_msg, &p->decoded) &&
p->decoded.portnum != meshtastic_PortNum_UNKNOWN_APP) {
decrypted = true;
LOG_INFO("Packet decrypted using PKI!\n");
p->pki_encrypted = true;

but at this point the channel is still hashed and probably won't be equal to 0, only later does the channel unhash.

@jp-bennett
Copy link
Collaborator

but at this point the channel is still hashed and probably won't be equal to 0, only later does the channel unhash.

PKI packets always set the hash to 0. That check is probably superfluous, but I don't think it would cause problems.

@slawekgajzner
Copy link

What about is_licensed, if it is set to true then PKI is not used so the pki_encrypted flag will not be set,
maybe that's why admin doesn't work.
If I set is_licensed to true I get the No Response message.
If I turn off is_licensed (License amateur radio) everything works

Router.cpp
if (!owner.is_licensed && config.security.private_key.size == 32 && p->to != NODENUM_BROADCAST && node != nullptr && node->user.public_key.size > 0 && p->decoded.port num != meshtastic_PortNum_TRACEROUTE_APP && p->decoded.portnum != meshtastic_PortNum_NODEINFO_APP && p->decoded.portnum != meshtastic_PortNum_ROUTING_APP && p->decoded.portnum != meshtastic_PortNum_POSITION_APP)
{
...

@jp-bennett
Copy link
Collaborator

What about is_licensed

Ham mode means no encryption at all. Definitely precludes PKI for admin. Though using the legacy admin channel would likely work.

@garthvh
Copy link
Member

garthvh commented Sep 15, 2024

You should not be able to use the legacy admin channel with no encryption

@pyro2927
Copy link

@jp-bennett looks like my T-Deck is experiencing this issue, which is weird because I have confirmed the keys are not changing and are correct. Tried to send DMs and had this problem.

I switched to using two Heltec v3s (both on 2.5.0.9ac0e26). Reset Node DBs on all three devices. Was able to get admin controls to work, but am still seeing weird errors of "Public Key Mismatch" intermittently.

@jp-bennett
Copy link
Collaborator

@jp-bennett looks like my T-Deck is experiencing this issue, which is weird because I have confirmed the keys are not changing and are correct. Tried to send DMs and had this problem.

I switched to using two Heltec v3s (both on 2.5.0.9ac0e26). Reset Node DBs on all three devices. Was able to get admin controls to work, but am still seeing weird errors of "Public Key Mismatch" intermittently.

There seems to be a false positive in iOS, causing that key mismatch error. It's getting worked on.

@thatSFguy
Copy link
Author

Sorry, I'm caught up with personal stuff and work, so I've not had a chance to test with the CLI. I did a fresh install with complete erase on all nodes to eliminate any potential legacy issues before opening this bug.

@jp-bennett
Copy link
Collaborator

Both of my devices are on 2.5, so I don't think that would be the issue. That said, I hadn't added the public key of my primary node as the admin key on the other. After doing that I run into a slightly different issue:

$ meshtastic --host 192.168.1.25 --dest '!bd4c2170' --get device
Connected to radio
Requesting current config from remote node (this can take a while).
Aborting due to: Timed out waiting for an acknowledgment

Could you snag a serial output log on the node to be controlled, when this happens? This is a really interesting case.

@thatSFguy
Copy link
Author

thatSFguy commented Sep 18, 2024 •
edited
Loading

here is the output of a admin request from Android 2.4.8. Nodes are running 2.5.1 . Log is from the receiving node. DM was working prior to the admin request.

DEBUG | 02:27:13 181 [RadioIf] (bw=250, sf=11, cr=4/5) packet symLen=8 ms, payloadSize=26, time 428 ms
DEBUG | 02:27:13 181 [RadioIf] Lora RX (id=0x0695114f fr=0xd8 to=0xa4, WantAck=1, HopLim=7 Ch=0xd2 encrypted rxSNR=12.5 rxRSSI=-27 hopStart=7)
DEBUG | 02:27:13 181 [RadioIf] AirTime - Packet received : 428ms
DEBUG | 02:27:13 181 [Router] Add packet record (id=0x0695114f fr=0xd8 to=0xa4, WantAck=1, HopLim=7 Ch=0xd2 encrypted rxSNR=12.5 rxRSSI=-27 hopStart=7)
DEBUG | 02:27:13 181 [Router] Using channel 1 (hash 0xd2)
DEBUG | 02:27:13 181 [Router] Using AES256 key!
DEBUG | 02:27:13 181 [Router] decoded message (id=0x0695114f fr=0xd8 to=0xa4, WantAck=1, HopLim=7 Ch=0x1 Portnum=6 WANTRESP rxtime=1726626433 rxSNR=12.5 rxRSSI=-27 hopStart=7)
DEBUG | 02:27:13 181 [Router] handleReceived(REMOTE) (id=0x0695114f fr=0xd8 to=0xa4, WantAck=1, HopLim=7 Ch=0x1 Portnum=6 WANTRESP rxtime=1726626433 rxSNR=12.5 rxRSSI=-27 hopStart=7)
DEBUG | 02:27:13 181 [Router] Module 'Admin' wantsPacket=1
INFO  | 02:27:13 181 [Router] Received Admin from=0x1c2cbfd8, id=0x695114f, portnum=6, payloadlen=2
INFO  | 02:27:13 181 [Router] Handling admin payload 1
INFO  | 02:27:13 181 [Router] Client is getting channel 0
DEBUG | 02:27:13 181 [Router] Setting admin key to : 2d cf 46 29 04 b4 78 d8 
DEBUG | 02:27:13 181 [Router] Partially randomized packet id 1360079679
INFO  | 02:27:13 181 [Router] Asked module 'Admin' to send a response
DEBUG | 02:27:13 181 [Router] Module 'routing' wantsPacket=1
INFO  | 02:27:13 181 [Router] Received routing from=0x1c2cbfd8, id=0x695114f, portnum=6, payloadlen=2
DEBUG | 02:27:13 181 [Router] Routing sniffing (id=0x0695114f fr=0xd8 to=0xa4, WantAck=1, HopLim=7 Ch=0x1 Portnum=6 WANTRESP rxtime=1726626433 rxSNR=12.5 rxRSSI=-27 hopStart=7)
DEBUG | 02:27:13 181 [Router] Some other module has replied to this message, no need for a 2nd ack
DEBUG | 02:27:13 181 [Router] Delivering rx packet (id=0x0695114f fr=0xd8 to=0xa4, WantAck=1, HopLim=7 Ch=0x1 Portnum=6 WANTRESP rxtime=1726626433 rxSNR=12.5 rxRSSI=-27 hopStart=7)
DEBUG | 02:27:13 181 [Router] Update DB node 0x1c2cbfd8, rx_time=1726626433
DEBUG | 02:27:13 181 [Router] Forwarding to phone (id=0x0695114f fr=0xd8 to=0xa4, WantAck=1, HopLim=7 Ch=0x1 Portnum=6 WANTRESP rxtime=1726626433 rxSNR=12.5 rxRSSI=-27 hopStart=7)
DEBUG | 02:27:13 181 [Router] Module 'routing' considered
DEBUG | 02:27:13 182 [Router] Sending response (id=0x51112b3f fr=0xa4 to=0xd8, WantAck=1, HopLim=2 Ch=0x1 Portnum=6 requestId=695114f rxtime=1726626433 priority=70)
DEBUG | 02:27:13 182 [Router] Update DB node 0x25c0dba4, rx_time=1726626433
DEBUG | 02:27:13 182 [Router] (bw=250, sf=11, cr=4/5) packet symLen=8 ms, payloadSize=47, time 583 ms
DEBUG | 02:27:13 182 [Router] Setting next retransmission in 8284 msecs:  (id=0x51112b3f fr=0xa4 to=0xd8, WantAck=1, HopLim=2 Ch=0x1 Portnum=6 requestId=695114f rxtime=1726626433 priority=70)
DEBUG | 02:27:13 182 [Router] Add packet record (id=0x51112b3f fr=0xa4 to=0xd8, WantAck=1, HopLim=2 Ch=0x1 Portnum=6 requestId=695114f rxtime=1726626433 priority=70)
DEBUG | 02:27:13 182 [Router] Using AES256 key!
DEBUG | 02:27:13 182 [Router] enqueuing for send (id=0x51112b3f fr=0xa4 to=0xd8, WantAck=1, HopLim=2 Ch=0xd2 encrypted rxtime=1726626433 hopStart=2 priority=70)
DEBUG | 02:27:13 182 [Router] txGood=3,rxGood=8,rxBad=0
WARN  | 02:27:13 182 [RadioIf] Can not send yet, busyRx
DEBUG | 02:27:13 182 [RadioIf] (bw=250, sf=11, cr=4/5) packet symLen=8 ms, payloadSize=26, time 428 ms
DEBUG | 02:27:13 182 [RadioIf] Lora RX (id=0x06951150 fr=0xd8 to=0xa4, WantAck=1, HopLim=7 Ch=0xd2 encrypted rxSNR=12 rxRSSI=-26 hopStart=7)
DEBUG | 02:27:13 182 [RadioIf] AirTime - Packet received : 428ms
DEBUG | 02:27:13 182 [Router] (bw=250, sf=11, cr=4/5) packet symLen=8 ms, payloadSize=26, time 428 ms
DEBUG | 02:27:13 182 [Router] Add packet record (id=0x06951150 fr=0xd8 to=0xa4, WantAck=1, HopLim=7 Ch=0xd2 encrypted rxSNR=12 rxRSSI=-26 hopStart=7)
DEBUG | 02:27:13 182 [Router] Using channel 1 (hash 0xd2)
DEBUG | 02:27:13 182 [Router] Using AES256 key!
DEBUG | 02:27:13 182 [Router] decoded message (id=0x06951150 fr=0xd8 to=0xa4, WantAck=1, HopLim=7 Ch=0x1 Portnum=6 WANTRESP rxtime=1726626433 rxSNR=12 rxRSSI=-26 hopStart=7)
DEBUG | 02:27:13 182 [Router] handleReceived(REMOTE) (id=0x06951150 fr=0xd8 to=0xa4, WantAck=1, HopLim=7 Ch=0x1 Portnum=6 WANTRESP rxtime=1726626433 rxSNR=12 rxRSSI=-26 hopStart=7)
DEBUG | 02:27:13 182 [Router] Module 'Admin' wantsPacket=1
INFO  | 02:27:13 182 [Router] Received Admin from=0x1c2cbfd8, id=0x6951150, portnum=6, payloadlen=2
INFO  | 02:27:13 182 [Router] Ignoring admin payload 5
INFO  | 02:27:13 182 [Router] Asked module 'Admin' to send a response
DEBUG | 02:27:13 182 [Router] Module 'routing' wantsPacket=1
INFO  | 02:27:13 182 [Router] Received routing from=0x1c2cbfd8, id=0x6951150, portnum=6, payloadlen=2
DEBUG | 02:27:13 182 [Router] Routing sniffing (id=0x06951150 fr=0xd8 to=0xa4, WantAck=1, HopLim=7 Ch=0x1 Portnum=6 WANTRESP rxtime=1726626433 rxSNR=12 rxRSSI=-26 hopStart=7)
DEBUG | 02:27:13 182 [Router] Partially randomized packet id 3549609792
DEBUG | 02:27:13 182 [Router] (bw=250, sf=11, cr=4/5) packet symLen=8 ms, payloadSize=27, time 436 ms
DEBUG | 02:27:13 182 [Router] Add packet record (id=0xd392bf40 fr=0xa4 to=0xd8, WantAck=0, HopLim=2 Ch=0x1 Portnum=5 requestId=6951150 rxtime=1726626433 priority=120)
DEBUG | 02:27:13 182 [Router] Using AES256 key!
DEBUG | 02:27:13 182 [Router] enqueuing for send (id=0xd392bf40 fr=0xa4 to=0xd8, WantAck=0, HopLim=2 Ch=0xd2 encrypted rxtime=1726626433 hopStart=2 priority=120)
DEBUG | 02:27:13 182 [Router] txGood=3,rxGood=9,rxBad=0
DEBUG | 02:27:13 182 [Router] Delivering rx packet (id=0x06951150 fr=0xd8 to=0xa4, WantAck=1, HopLim=7 Ch=0x1 Portnum=6 WANTRESP rxtime=1726626433 rxSNR=12 rxRSSI=-26 hopStart=7)
DEBUG | 02:27:13 182 [Router] Update DB node 0x1c2cbfd8, rx_time=1726626433
DEBUG | 02:27:14 182 [Router] Forwarding to phone (id=0x06951150 fr=0xd8 to=0xa4, WantAck=1, HopLim=7 Ch=0x1 Portnum=6 WANTRESP rxtime=1726626433 rxSNR=12 rxRSSI=-26 hopStart=7)
INFO  | 02:27:14 182 [Router] Asked module 'routing' to send a response
DEBUG | 02:27:14 182 [Router] No one responded, send a nak
DEBUG | 02:27:14 182 [Router] Partially randomized packet id 910903105
WARN  | 02:27:14 182 [Router] Alloc an err=8,to=0x1c2cbfd8,idFrom=0x6951150,id=0x364b4741
DEBUG | 02:27:14 182 [Router] (bw=250, sf=11, cr=4/5) packet symLen=8 ms, payloadSize=27, time 436 ms
DEBUG | 02:27:14 182 [Router] Add packet record (id=0x364b4741 fr=0xa4 to=0xd8, WantAck=0, HopLim=2 Ch=0x1 Portnum=5 requestId=6951150 rxtime=1726626434 priority=120)
DEBUG | 02:27:14 182 [Router] Using AES256 key!
DEBUG | 02:27:14 182 [Router] enqueuing for send (id=0x364b4741 fr=0xa4 to=0xd8, WantAck=0, HopLim=2 Ch=0xd2 encrypted rxtime=1726626434 hopStart=2 priority=120)
DEBUG | 02:27:14 182 [Router] txGood=3,rxGood=9,rxBad=0
WARN  | 02:27:14 182 [RadioIf] Can not send yet, busyRx
WARN  | 02:27:14 182 [RadioIf] Can not send yet, busyRx
DEBUG | 02:27:14 182 [RadioIf] (bw=250, sf=11, cr=4/5) packet symLen=8 ms, payloadSize=24, time 411 ms
DEBUG | 02:27:14 182 [RadioIf] Lora RX (id=0x0695114f fr=0xd8 to=0xa4, WantAck=1, HopLim=6 Ch=0xd2 encrypted rxSNR=9 rxRSSI=-78 hopStart=7)
DEBUG | 02:27:14 182 [RadioIf] AirTime - Packet received : 411ms
DEBUG | 02:27:14 182 [Router] (bw=250, sf=11, cr=4/5) packet symLen=8 ms, payloadSize=24, time 411 ms
DEBUG | 02:27:14 182 [Router] Found existing packet record for fr=0x1c2cbfd8,to=0x25c0dba4,id=0x695114f
DEBUG | 02:27:14 182 [Router] Found existing packet record for fr=0x1c2cbfd8,to=0x25c0dba4,id=0x695114f
DEBUG | 02:27:14 182 [Router] Add packet record (id=0x0695114f fr=0xd8 to=0xa4, WantAck=1, HopLim=6 Ch=0xd2 encrypted rxSNR=9 rxRSSI=-78 hopStart=7)
DEBUG | 02:27:14 182 [Router] Ignoring incoming msg we've already seen (id=0x0695114f fr=0xd8 to=0xa4, WantAck=1, HopLim=6 Ch=0xd2 encrypted rxSNR=9 rxRSSI=-78 hopStart=7)
DEBUG | 02:27:14 182 [Router] cancelSending id=0x695114f, removed=0
DEBUG | 02:27:14 182 [Router] Incoming message was filtered from 0x1c2cbfd8
WARN  | 02:27:14 183 [RadioIf] Can not send yet, busyRx
WARN  | 02:27:14 183 [RadioIf] Can not send yet, busyRx
WARN  | 02:27:14 183 [RadioIf] Can not send yet, busyRx
DEBUG | 02:27:14 183 [RadioIf] (bw=250, sf=11, cr=4/5) packet symLen=8 ms, payloadSize=38, time 518 ms
DEBUG | 02:27:14 183 [RadioIf] Lora RX (id=0x06951150 fr=0xd8 to=0xa4, WantAck=1, HopLim=6 Ch=0x0 encrypted rxSNR=11.75 rxRSSI=-54 hopStart=7)
DEBUG | 02:27:14 183 [RadioIf] AirTime - Packet received : 518ms
DEBUG | 02:27:14 183 [Router] (bw=250, sf=11, cr=4/5) packet symLen=8 ms, payloadSize=38, time 518 ms
DEBUG | 02:27:14 183 [Router] Found existing packet record for fr=0x1c2cbfd8,to=0x25c0dba4,id=0x6951150
DEBUG | 02:27:14 183 [Router] Found existing packet record for fr=0x1c2cbfd8,to=0x25c0dba4,id=0x6951150
DEBUG | 02:27:14 183 [Router] Add packet record (id=0x06951150 fr=0xd8 to=0xa4, WantAck=1, HopLim=6 Ch=0x0 encrypted rxSNR=11.75 rxRSSI=-54 hopStart=7)
DEBUG | 02:27:15 183 [Router] Ignoring incoming msg we've already seen (id=0x06951150 fr=0xd8 to=0xa4, WantAck=1, HopLim=6 Ch=0x0 encrypted rxSNR=11.75 rxRSSI=-54 hopStart=7)
DEBUG | 02:27:15 183 [Router] cancelSending id=0x6951150, removed=0
DEBUG | 02:27:15 183 [Router] Incoming message was filtered from 0x1c2cbfd8
WARN  | 02:27:15 183 [RadioIf] Can not send yet, busyRx
WARN  | 02:27:15 183 [RadioIf] Can not send yet, busyRx
WARN  | 02:27:15 184 [RadioIf] Can not send yet, busyRx
DEBUG | 02:27:15 184 [RadioIf] (bw=250, sf=11, cr=4/5) packet symLen=8 ms, payloadSize=24, time 411 ms
DEBUG | 02:27:15 184 [RadioIf] Lora RX (id=0x0695114f fr=0xd8 to=0xa4, WantAck=1, HopLim=6 Ch=0xd2 encrypted rxSNR=13 rxRSSI=-59 hopStart=7)
DEBUG | 02:27:15 184 [RadioIf] AirTime - Packet received : 411ms
DEBUG | 02:27:15 184 [Router] (bw=250, sf=11, cr=4/5) packet symLen=8 ms, payloadSize=24, time 411 ms
DEBUG | 02:27:15 184 [Router] Found existing packet record for fr=0x1c2cbfd8,to=0x25c0dba4,id=0x695114f
DEBUG | 02:27:15 184 [Router] Found existing packet record for fr=0x1c2cbfd8,to=0x25c0dba4,id=0x695114f
DEBUG | 02:27:15 184 [Router] Add packet record (id=0x0695114f fr=0xd8 to=0xa4, WantAck=1, HopLim=6 Ch=0xd2 encrypted rxSNR=13 rxRSSI=-59 hopStart=7)
DEBUG | 02:27:15 184 [Router] Ignoring incoming msg we've already seen (id=0x0695114f fr=0xd8 to=0xa4, WantAck=1, HopLim=6 Ch=0xd2 encrypted rxSNR=13 rxRSSI=-59 hopStart=7)
DEBUG | 02:27:15 184 [Router] cancelSending id=0x695114f, removed=0
DEBUG | 02:27:15 184 [Router] Incoming message was filtered from 0x1c2cbfd8
WARN  | 02:27:15 184 [RadioIf] Can not send yet, busyRx
WARN  | 02:27:15 184 [RadioIf] Can not send yet, busyRx
WARN  | 02:27:15 184 [RadioIf] Can not send yet, busyRx
DEBUG | 02:27:16 184 [RadioIf] (bw=250, sf=11, cr=4/5) packet symLen=8 ms, payloadSize=24, time 411 ms
DEBUG | 02:27:16 184 [RadioIf] Lora RX (id=0x06951150 fr=0xd8 to=0xa4, WantAck=1, HopLim=6 Ch=0xd2 encrypted rxSNR=13 rxRSSI=-59 hopStart=7)
DEBUG | 02:27:16 184 [RadioIf] AirTime - Packet received : 411ms
DEBUG | 02:27:16 184 [Router] (bw=250, sf=11, cr=4/5) packet symLen=8 ms, payloadSize=24, time 411 ms
DEBUG | 02:27:16 184 [Router] Found existing packet record for fr=0x1c2cbfd8,to=0x25c0dba4,id=0x6951150
DEBUG | 02:27:16 184 [Router] Found existing packet record for fr=0x1c2cbfd8,to=0x25c0dba4,id=0x6951150
DEBUG | 02:27:16 184 [Router] Add packet record (id=0x06951150 fr=0xd8 to=0xa4, WantAck=1, HopLim=6 Ch=0xd2 encrypted rxSNR=13 rxRSSI=-59 hopStart=7)
DEBUG | 02:27:16 184 [Router] Ignoring incoming msg we've already seen (id=0x06951150 fr=0xd8 to=0xa4, WantAck=1, HopLim=6 Ch=0xd2 encrypted rxSNR=13 rxRSSI=-59 hopStart=7)
DEBUG | 02:27:16 184 [Router] cancelSending id=0x6951150, removed=0
DEBUG | 02:27:16 184 [Router] Incoming message was filtered from 0x1c2cbfd8
DEBUG | 02:27:16 184 [RadioIf] Starting low level send (id=0xd392bf40 fr=0xa4 to=0xd8, WantAck=0, HopLim=2 Ch=0xd2 encrypted rxtime=1726626433 hopStart=2 priority=120)
DEBUG | 02:27:16 184 [RadioIf] (bw=250, sf=11, cr=4/5) packet symLen=8 ms, payloadSize=29, time 452 ms
DEBUG | 02:27:16 184 [RadioIf] AirTime - Packet transmitted : 452ms
DEBUG | 02:27:16 185 [RadioIf] Completed sending (id=0xd392bf40 fr=0xa4 to=0xd8, WantAck=0, HopLim=2 Ch=0xd2 encrypted rxtime=1726626433 hopStart=2 priority=120)
WARN  | 02:27:16 185 [RadioIf] Can not send yet, busyRx
WARN  | 02:27:17 185 [RadioIf] Can not send yet, busyRx
WARN  | 02:27:17 185 [RadioIf] Can not send yet, busyRx
DEBUG | 02:27:17 185 [RadioIf] (bw=250, sf=11, cr=4/5) packet symLen=8 ms, payloadSize=27, time 436 ms
DEBUG | 02:27:17 185 [RadioIf] Lora RX (id=0xd392bf40 fr=0xa4 to=0xd8, WantAck=0, HopLim=1 Ch=0xd2 encrypted rxSNR=13 rxRSSI=-58 hopStart=2)
DEBUG | 02:27:17 185 [RadioIf] AirTime - Packet received : 436ms
DEBUG | 02:27:17 185 [Router] Rx someone rebroadcasting for us (id=0xd392bf40 fr=0xa4 to=0xd8, WantAck=0, HopLim=1 Ch=0xd2 encrypted rxSNR=13 rxRSSI=-58 hopStart=2)
DEBUG | 02:27:17 185 [Router] didn't find pending packet
DEBUG | 02:27:17 185 [Router] (bw=250, sf=11, cr=4/5) packet symLen=8 ms, payloadSize=27, time 436 ms
DEBUG | 02:27:17 185 [Router] Found existing packet record for fr=0x25c0dba4,to=0x1c2cbfd8,id=0xd392bf40
DEBUG | 02:27:17 185 [Router] Found existing packet record for fr=0x25c0dba4,to=0x1c2cbfd8,id=0xd392bf40
DEBUG | 02:27:17 185 [Router] Add packet record (id=0xd392bf40 fr=0xa4 to=0xd8, WantAck=0, HopLim=1 Ch=0xd2 encrypted rxSNR=13 rxRSSI=-58 hopStart=2)
DEBUG | 02:27:17 185 [Router] Ignoring incoming msg we've already seen (id=0xd392bf40 fr=0xa4 to=0xd8, WantAck=0, HopLim=1 Ch=0xd2 encrypted rxSNR=13 rxRSSI=-58 hopStart=2)
DEBUG | 02:27:17 186 [Router] cancelSending id=0xd392bf40, removed=0
DEBUG | 02:27:17 186 [Router] Incoming message was filtered from 0x25c0dba4
DEBUG | 02:27:17 186 [RadioIf] Starting low level send (id=0x364b4741 fr=0xa4 to=0xd8, WantAck=0, HopLim=2 Ch=0xd2 encrypted rxtime=1726626434 hopStart=2 priority=120)
DEBUG | 02:27:17 186 [RadioIf] (bw=250, sf=11, cr=4/5) packet symLen=8 ms, payloadSize=29, time 452 ms
DEBUG | 02:27:17 186 [RadioIf] AirTime - Packet transmitted : 452ms
DEBUG | 02:27:18 186 [RadioIf] Completed sending (id=0x364b4741 fr=0xa4 to=0xd8, WantAck=0, HopLim=2 Ch=0xd2 encrypted rxtime=1726626434 hopStart=2 priority=120)
DEBUG | 02:27:18 186 [RadioIf] Starting low level send (id=0x51112b3f fr=0xa4 to=0xd8, WantAck=1, HopLim=2 Ch=0xd2 encrypted rxtime=1726626433 hopStart=2 priority=70)
DEBUG | 02:27:18 186 [RadioIf] (bw=250, sf=11, cr=4/5) packet symLen=8 ms, payloadSize=49, time 600 ms
DEBUG | 02:27:18 186 [RadioIf] AirTime - Packet transmitted : 600ms
DEBUG | 02:27:18 187 [RadioIf] Completed sending (id=0x51112b3f fr=0xa4 to=0xd8, WantAck=1, HopLim=2 Ch=0xd2 encrypted rxtime=1726626433 hopStart=2 priority=70)
DEBUG | 02:27:19 188 [RadioIf] (bw=250, sf=11, cr=4/5) packet symLen=8 ms, payloadSize=47, time 583 ms
DEBUG | 02:27:19 188 [RadioIf] Lora RX (id=0x51112b3f fr=0xa4 to=0xd8, WantAck=1, HopLim=1 Ch=0xd2 encrypted rxSNR=10 rxRSSI=-75 hopStart=2)
DEBUG | 02:27:19 188 [RadioIf] AirTime - Packet received : 583ms
DEBUG | 02:27:19 188 [Router] Rx someone rebroadcasting for us (id=0x51112b3f fr=0xa4 to=0xd8, WantAck=1, HopLim=1 Ch=0xd2 encrypted rxSNR=10 rxRSSI=-75 hopStart=2)
DEBUG | 02:27:19 188 [Router] generating implicit ack
DEBUG | 02:27:19 188 [Router] Partially randomized packet id 1905991490
DEBUG | 02:27:19 188 [Router] Enqueued local (id=0x719b1f42 fr=0xa4 to=0xa4, WantAck=0, HopLim=7 Ch=0x1 Portnum=5 requestId=51112b3f rxtime=1726626439 priority=120)
DEBUG | 02:27:19 188 [Router] Found existing packet record for fr=0x25c0dba4,to=0x1c2cbfd8,id=0x51112b3f
DEBUG | 02:27:19 188 [Router] Found existing packet record for fr=0x25c0dba4,to=0x1c2cbfd8,id=0x51112b3f
DEBUG | 02:27:19 188 [Router] Add packet record (id=0x51112b3f fr=0xa4 to=0xd8, WantAck=1, HopLim=1 Ch=0xd2 encrypted rxSNR=10 rxRSSI=-75 hopStart=2)
DEBUG | 02:27:19 188 [Router] Ignoring incoming msg we've already seen (id=0x51112b3f fr=0xa4 to=0xd8, WantAck=1, HopLim=1 Ch=0xd2 encrypted rxSNR=10 rxRSSI=-75 hopStart=2)
DEBUG | 02:27:19 188 [Router] cancelSending id=0x51112b3f, removed=0
DEBUG | 02:27:19 188 [Router] Incoming message was filtered from 0x25c0dba4
DEBUG | 02:27:19 188 [Router] Rx someone rebroadcasting for us (id=0x719b1f42 fr=0xa4 to=0xa4, WantAck=0, HopLim=7 Ch=0x1 Portnum=5 requestId=51112b3f rxtime=1726626439 priority=120)
DEBUG | 02:27:19 188 [Router] didn't find pending packet
DEBUG | 02:27:19 188 [Router] Add packet record (id=0x719b1f42 fr=0xa4 to=0xa4, WantAck=0, HopLim=7 Ch=0x1 Portnum=5 requestId=51112b3f rxtime=1726626439 priority=120)
DEBUG | 02:27:19 188 [Router] handleReceived(REMOTE) (id=0x719b1f42 fr=0xa4 to=0xa4, WantAck=0, HopLim=7 Ch=0x1 Portnum=5 requestId=51112b3f rxtime=1726626439 priority=120)
DEBUG | 02:27:19 188 [Router] Module 'routing' wantsPacket=1
INFO  | 02:27:19 188 [Router] Received routing from=0x25c0dba4, id=0x719b1f42, portnum=5, payloadlen=2
DEBUG | 02:27:19 188 [Router] Routing sniffing (id=0x719b1f42 fr=0xa4 to=0xa4, WantAck=0, HopLim=7 Ch=0x1 Portnum=5 requestId=51112b3f rxtime=1726626439 priority=120)
DEBUG | 02:27:19 188 [Router] Received an ack for 0x51112b3f, stopping retransmissions
DEBUG | 02:27:19 188 [Router] Delivering rx packet (id=0x719b1f42 fr=0xa4 to=0xa4, WantAck=0, HopLim=7 Ch=0x1 Portnum=5 requestId=51112b3f rxtime=1726626439 priority=120)
DEBUG | 02:27:19 188 [Router] Update DB node 0x25c0dba4, rx_time=1726626439
DEBUG | 02:27:19 188 [Router] Forwarding to phone (id=0x719b1f42 fr=0xa4 to=0xa4, WantAck=0, HopLim=7 Ch=0x1 Portnum=5 requestId=51112b3f rxtime=1726626439 priority=120)
DEBUG | 02:27:19 188 [Router] Module 'routing' considered
DEBUG | 02:27:19 188 [RadioIf] (bw=250, sf=11, cr=4/5) packet symLen=8 ms, payloadSize=27, time 436 ms
DEBUG | 02:27:19 188 [RadioIf] Lora RX (id=0x364b4741 fr=0xa4 to=0xd8, WantAck=0, HopLim=1 Ch=0xd2 encrypted rxSNR=10 rxRSSI=-78 hopStart=2)
DEBUG | 02:27:19 188 [RadioIf] AirTime - Packet received : 436ms
DEBUG | 02:27:19 188 [Router] Rx someone rebroadcasting for us (id=0x364b4741 fr=0xa4 to=0xd8, WantAck=0, HopLim=1 Ch=0xd2 encrypted rxSNR=10 rxRSSI=-78 hopStart=2)
DEBUG | 02:27:19 188 [Router] didn't find pending packet
DEBUG | 02:27:19 188 [Router] Found existing packet record for fr=0x25c0dba4,to=0x1c2cbfd8,id=0x364b4741
DEBUG | 02:27:19 188 [Router] Found existing packet record for fr=0x25c0dba4,to=0x1c2cbfd8,id=0x364b4741
DEBUG | 02:27:19 188 [Router] Add packet record (id=0x364b4741 fr=0xa4 to=0xd8, WantAck=0, HopLim=1 Ch=0xd2 encrypted rxSNR=10 rxRSSI=-78 hopStart=2)
DEBUG | 02:27:20 188 [Router] Ignoring incoming msg we've already seen (id=0x364b4741 fr=0xa4 to=0xd8, WantAck=0, HopLim=1 Ch=0xd2 encrypted rxSNR=10 rxRSSI=-78 hopStart=2)
DEBUG | 02:27:20 188 [Router] cancelSending id=0x364b4741, removed=0
DEBUG | 02:27:20 188 [Router] Incoming message was filtered from 0x25c0dba4
DEBUG | 02:27:20 189 [RadioIf] (bw=250, sf=11, cr=4/5) packet symLen=8 ms, payloadSize=47, time 583 ms
DEBUG | 02:27:20 189 [RadioIf] Lora RX (id=0x51112b3f fr=0xa4 to=0xd8, WantAck=1, HopLim=0 Ch=0xd2 encrypted rxSNR=13.25 rxRSSI=-58 hopStart=2)
DEBUG | 02:27:20 189 [RadioIf] AirTime - Packet received : 583ms
DEBUG | 02:27:20 189 [Router] Rx someone rebroadcasting for us (id=0x51112b3f fr=0xa4 to=0xd8, WantAck=1, HopLim=0 Ch=0xd2 encrypted rxSNR=13.25 rxRSSI=-58 hopStart=2)
DEBUG | 02:27:20 189 [Router] didn't find pending packet
DEBUG | 02:27:20 189 [Router] Found existing packet record for fr=0x25c0dba4,to=0x1c2cbfd8,id=0x51112b3f
DEBUG | 02:27:20 189 [Router] Found existing packet record for fr=0x25c0dba4,to=0x1c2cbfd8,id=0x51112b3f
DEBUG | 02:27:20 189 [Router] Add packet record (id=0x51112b3f fr=0xa4 to=0xd8, WantAck=1, HopLim=0 Ch=0xd2 encrypted rxSNR=13.25 rxRSSI=-58 hopStart=2)
DEBUG | 02:27:20 189 [Router] Ignoring incoming msg we've already seen (id=0x51112b3f fr=0xa4 to=0xd8, WantAck=1, HopLim=0 Ch=0xd2 encrypted rxSNR=13.25 rxRSSI=-58 hopStart=2)
DEBUG | 02:27:20 189 [Router] cancelSending id=0x51112b3f, removed=0
DEBUG | 02:27:20 189 [Router] Incoming message was filtered from 0x25c0dba4
DEBUG | 02:27:21 189 [RadioIf] (bw=250, sf=11, cr=4/5) packet symLen=8 ms, payloadSize=29, time 452 ms
DEBUG | 02:27:21 189 [RadioIf] Lora RX (id=0x364b4741 fr=0xa4 to=0xd8, WantAck=0, HopLim=1 Ch=0xd2 encrypted rxSNR=11.75 rxRSSI=-55 hopStart=2)
DEBUG | 02:27:21 189 [RadioIf] AirTime - Packet received : 452ms
DEBUG | 02:27:21 189 [Router] Rx someone rebroadcasting for us (id=0x364b4741 fr=0xa4 to=0xd8, WantAck=0, HopLim=1 Ch=0xd2 encrypted rxSNR=11.75 rxRSSI=-55 hopStart=2)
DEBUG | 02:27:21 189 [Router] didn't find pending packet
DEBUG | 02:27:21 189 [Router] Found existing packet record for fr=0x25c0dba4,to=0x1c2cbfd8,id=0x364b4741
DEBUG | 02:27:21 189 [Router] Found existing packet record for fr=0x25c0dba4,to=0x1c2cbfd8,id=0x364b4741
DEBUG | 02:27:21 189 [Router] Add packet record (id=0x364b4741 fr=0xa4 to=0xd8, WantAck=0, HopLim=1 Ch=0xd2 encrypted rxSNR=11.75 rxRSSI=-55 hopStart=2)
DEBUG | 02:27:21 189 [Router] Ignoring incoming msg we've already seen (id=0x364b4741 fr=0xa4 to=0xd8, WantAck=0, HopLim=1 Ch=0xd2 encrypted rxSNR=11.75 rxRSSI=-55 hopStart=2)
DEBUG | 02:27:21 189 [Router] cancelSending id=0x364b4741, removed=0
DEBUG | 02:27:21 189 [Router] Incoming message was filtered from 0x25c0dba4
DEBUG | 02:27:21 190 [RadioIf] (bw=250, sf=11, cr=4/5) packet symLen=8 ms, payloadSize=29, time 452 ms
DEBUG | 02:27:21 190 [RadioIf] Lora RX (id=0x7bcd5bd3 fr=0xd8 to=0xa4, WantAck=0, HopLim=2 Ch=0xd2 encrypted rxSNR=12.25 rxRSSI=-26 hopStart=2)
DEBUG | 02:27:21 190 [RadioIf] AirTime - Packet received : 452ms
DEBUG | 02:27:21 190 [Router] Add packet record (id=0x7bcd5bd3 fr=0xd8 to=0xa4, WantAck=0, HopLim=2 Ch=0xd2 encrypted rxSNR=12.25 rxRSSI=-26 hopStart=2)
DEBUG | 02:27:21 190 [Router] Using channel 1 (hash 0xd2)
DEBUG | 02:27:21 190 [Router] Using AES256 key!
DEBUG | 02:27:21 190 [Router] decoded message (id=0x7bcd5bd3 fr=0xd8 to=0xa4, WantAck=0, HopLim=2 Ch=0x1 Portnum=5 requestId=51112b3f rxtime=1726626441 rxSNR=12.25 rxRSSI=-26 hopStart=2)
DEBUG | 02:27:21 190 [Router] handleReceived(REMOTE) (id=0x7bcd5bd3 fr=0xd8 to=0xa4, WantAck=0, HopLim=2 Ch=0x1 Portnum=5 requestId=51112b3f rxtime=1726626441 rxSNR=12.25 rxRSSI=-26 hopSta
DEBUG | 02:27:21 190 [Router] Module 'routing' wantsPacket=1
INFO  | 02:27:21 190 [Router] Received routing from=0x1c2cbfd8, id=0x7bcd5bd3, portnum=5, payloadlen=2
DEBUG | 02:27:22 190 [Router] Routing sniffing (id=0x7bcd5bd3 fr=0xd8 to=0xa4, WantAck=0, HopLim=2 Ch=0x1 Portnum=5 requestId=51112b3f rxtime=1726626441 rxSNR=12.25 rxRSSI=-26 hopStart=2)
DEBUG | 02:27:22 190 [Router] Received an ack for 0x51112b3f, stopping retransmissions
DEBUG | 02:27:22 190 [Router] Delivering rx packet (id=0x7bcd5bd3 fr=0xd8 to=0xa4, WantAck=0, HopLim=2 Ch=0x1 Portnum=5 requestId=51112b3f rxtime=1726626441 rxSNR=12.25 rxRSSI=-26 hopStart
DEBUG | 02:27:22 190 [Router] Update DB node 0x1c2cbfd8, rx_time=1726626441
DEBUG | 02:27:22 190 [Router] Forwarding to phone (id=0x7bcd5bd3 fr=0xd8 to=0xa4, WantAck=0, HopLim=2 Ch=0x1 Portnum=5 requestId=51112b3f rxtime=1726626441 rxSNR=12.25 rxRSSI=-26 hopStart=
DEBUG | 02:27:22 190 [Router] Module 'routing' considered
DEBUG | 02:27:22 191 [RadioIf] (bw=250, sf=11, cr=4/5) packet symLen=8 ms, payloadSize=27, time 436 ms
DEBUG | 02:27:22 191 [RadioIf] Lora RX (id=0x7bcd5bd3 fr=0xd8 to=0xa4, WantAck=0, HopLim=1 Ch=0xd2 encrypted rxSNR=13.25 rxRSSI=-57 hopStart=2)
DEBUG | 02:27:22 191 [RadioIf] AirTime - Packet received : 436ms
DEBUG | 02:27:22 191 [Router] Found existing packet record for fr=0x1c2cbfd8,to=0x25c0dba4,id=0x7bcd5bd3
DEBUG | 02:27:22 191 [Router] Found existing packet record for fr=0x1c2cbfd8,to=0x25c0dba4,id=0x7bcd5bd3
DEBUG | 02:27:22 191 [Router] Add packet record (id=0x7bcd5bd3 fr=0xd8 to=0xa4, WantAck=0, HopLim=1 Ch=0xd2 encrypted rxSNR=13.25 rxRSSI=-57 hopStart=2)
DEBUG | 02:27:22 191 [Router] Ignoring incoming msg we've already seen (id=0x7bcd5bd3 fr=0xd8 to=0xa4, WantAck=0, HopLim=1 Ch=0xd2 encrypted rxSNR=13.25 rxRSSI=-57 hopStart=2)
DEBUG | 02:27:22 191 [Router] cancelSending id=0x7bcd5bd3, removed=0
DEBUG | 02:27:22 191 [Router] Incoming message was filtered from 0x1c2cbfd8
DEBUG | 02:27:23 191 [RadioIf] (bw=250, sf=11, cr=4/5) packet symLen=8 ms, payloadSize=26, time 428 ms
DEBUG | 02:27:23 191 [RadioIf] Lora RX (id=0x06951151 fr=0xd8 to=0xa4, WantAck=1, HopLim=7 Ch=0xd2 encrypted rxSNR=12.5 rxRSSI=-24 hopStart=7)
DEBUG | 02:27:23 191 [RadioIf] AirTime - Packet received : 428ms
DEBUG | 02:27:23 191 [Router] Add packet record (id=0x06951151 fr=0xd8 to=0xa4, WantAck=1, HopLim=7 Ch=0xd2 encrypted rxSNR=12.5 rxRSSI=-24 hopStart=7)
DEBUG | 02:27:23 191 [Router] Using channel 1 (hash 0xd2)
DEBUG | 02:27:23 191 [Router] Using AES256 key!
DEBUG | 02:27:23 191 [Router] decoded message (id=0x06951151 fr=0xd8 to=0xa4, WantAck=1, HopLim=7 Ch=0x1 Portnum=6 WANTRESP rxtime=1726626443 rxSNR=12.5 rxRSSI=-24 hopStart=7)
DEBUG | 02:27:23 191 [Router] handleReceived(REMOTE) (id=0x06951151 fr=0xd8 to=0xa4, WantAck=1, HopLim=7 Ch=0x1 Portnum=6 WANTRESP rxtime=1726626443 rxSNR=12.5 rxRSSI=-24 hopStart=7)
DEBUG | 02:27:23 191 [Router] Module 'Admin' wantsPacket=1
INFO  | 02:27:23 191 [Router] Received Admin from=0x1c2cbfd8, id=0x6951151, portnum=6, payloadlen=2
INFO  | 02:27:23 191 [Router] Handling admin payload 1
INFO  | 02:27:23 191 [Router] Client is getting channel 1
DEBUG | 02:27:23 191 [Router] Setting admin key to : 2d cf 46 29 04 b4 78 d8 
DEBUG | 02:27:23 191 [Router] Partially randomized packet id 3619727171
INFO  | 02:27:23 191 [Router] Asked module 'Admin' to send a response
DEBUG | 02:27:23 191 [Router] Module 'routing' wantsPacket=1
INFO  | 02:27:23 191 [Router] Received routing from=0x1c2cbfd8, id=0x6951151, portnum=6, payloadlen=2
DEBUG | 02:27:23 191 [Router] Routing sniffing (id=0x06951151 fr=0xd8 to=0xa4, WantAck=1, HopLim=7 Ch=0x1 Portnum=6 WANTRESP rxtime=1726626443 rxSNR=12.5 rxRSSI=-24 hopStart=7)
DEBUG | 02:27:23 191 [Router] Some other module has replied to this message, no need for a 2nd ack
DEBUG | 02:27:23 191 [Router] Delivering rx packet (id=0x06951151 fr=0xd8 to=0xa4, WantAck=1, HopLim=7 Ch=0x1 Portnum=6 WANTRESP rxtime=1726626443 rxSNR=12.5 rxRSSI=-24 hopStart=7)
DEBUG | 02:27:23 191 [Router] Update DB node 0x1c2cbfd8, rx_time=1726626443
DEBUG | 02:27:23 191 [Router] Forwarding to phone (id=0x06951151 fr=0xd8 to=0xa4, WantAck=1, HopLim=7 Ch=0x1 Portnum=6 WANTRESP rxtime=1726626443 rxSNR=12.5 rxRSSI=-24 hopStart=7)
DEBUG | 02:27:23 191 [Router] Module 'routing' considered
DEBUG | 02:27:23 192 [Router] Sending response (id=0xd7c0a743 fr=0xa4 to=0xd8, WantAck=1, HopLim=2 Ch=0x1 Portnum=6 requestId=6951151 rxtime=1726626443 priority=70)
DEBUG | 02:27:23 192 [Router] Update DB node 0x25c0dba4, rx_time=1726626443
DEBUG | 02:27:23 192 [Router] (bw=250, sf=11, cr=4/5) packet symLen=8 ms, payloadSize=85, time 870 ms
DEBUG | 02:27:23 192 [Router] Setting next retransmission in 8858 msecs:  (id=0xd7c0a743 fr=0xa4 to=0xd8, WantAck=1, HopLim=2 Ch=0x1 Portnum=6 requestId=6951151 rxtime=1726626443 priority=70)
DEBUG | 02:27:23 192 [Router] Add packet record (id=0xd7c0a743 fr=0xa4 to=0xd8, WantAck=1, HopLim=2 Ch=0x1 Portnum=6 requestId=6951151 rxtime=1726626443 priority=70)
DEBUG | 02:27:23 192 [Router] Using AES256 key!
DEBUG | 02:27:23 192 [Router] enqueuing for send (id=0xd7c0a743 fr=0xa4 to=0xd8, WantAck=1, HopLim=2 Ch=0xd2 encrypted rxtime=1726626443 hopStart=2 priority=70)
DEBUG | 02:27:23 192 [Router] txGood=6,rxGood=21,rxBad=0
WARN  | 02:27:23 192 [RadioIf] Can not send yet, busyRx
WARN  | 02:27:23 192 [RadioIf] Can not send yet, busyRx
WARN  | 02:27:23 192 [RadioIf] Can not send yet, busyRx
DEBUG | 02:27:23 192 [RadioIf] (bw=250, sf=11, cr=4/5) packet symLen=8 ms, payloadSize=24, time 411 ms
DEBUG | 02:27:23 192 [RadioIf] Lora RX (id=0x06951151 fr=0xd8 to=0xa4, WantAck=1, HopLim=6 Ch=0xd2 encrypted rxSNR=12 rxRSSI=-62 hopStart=7)
DEBUG | 02:27:23 192 [RadioIf] AirTime - Packet received : 411ms
DEBUG | 02:27:23 192 [Router] (bw=250, sf=11, cr=4/5) packet symLen=8 ms, payloadSize=24, time 411 ms
DEBUG | 02:27:23 192 [Router] Found existing packet record for fr=0x1c2cbfd8,to=0x25c0dba4,id=0x6951151
DEBUG | 02:27:23 192 [Router] Found existing packet record for fr=0x1c2cbfd8,to=0x25c0dba4,id=0x6951151
DEBUG | 02:27:23 192 [Router] Add packet record (id=0x06951151 fr=0xd8 to=0xa4, WantAck=1, HopLim=6 Ch=0xd2 encrypted rxSNR=12 rxRSSI=-62 hopStart=7)
DEBUG | 02:27:23 192 [Router] Ignoring incoming msg we've already seen (id=0x06951151 fr=0xd8 to=0xa4, WantAck=1, HopLim=6 Ch=0xd2 encrypted rxSNR=12 rxRSSI=-62 hopStart=7)
DEBUG | 02:27:23 192 [Router] cancelSending id=0x6951151, removed=0
DEBUG | 02:27:23 192 [Router] Incoming message was filtered from 0x1c2cbfd8
DEBUG | 02:27:24 192 [RadioIf] Starting low level send (id=0xd7c0a743 fr=0xa4 to=0xd8, WantAck=1, HopLim=2 Ch=0xd2 encrypted rxtime=1726626443 hopStart=2 priority=70)
DEBUG | 02:27:24 192 [RadioIf] (bw=250, sf=11, cr=4/5) packet symLen=8 ms, payloadSize=87, time 886 ms
DEBUG | 02:27:24 192 [RadioIf] AirTime - Packet transmitted : 886ms
DEBUG | 02:27:24 193 [RadioIf] Completed sending (id=0xd7c0a743 fr=0xa4 to=0xd8, WantAck=1, HopLim=2 Ch=0xd2 encrypted rxtime=1726626443 hopStart=2 priority=70)
DEBUG | 02:27:26 194 [RadioIf] (bw=250, sf=11, cr=4/5) packet symLen=8 ms, payloadSize=85, time 870 ms
DEBUG | 02:27:26 194 [RadioIf] Lora RX (id=0xd7c0a743 fr=0xa4 to=0xd8, WantAck=1, HopLim=1 Ch=0xd2 encrypted rxSNR=11.5 rxRSSI=-60 hopStart=2)
DEBUG | 02:27:26 194 [RadioIf] AirTime - Packet received : 870ms
DEBUG | 02:27:26 194 [Router] Rx someone rebroadcasting for us (id=0xd7c0a743 fr=0xa4 to=0xd8, WantAck=1, HopLim=1 Ch=0xd2 encrypted rxSNR=11.5 rxRSSI=-60 hopStart=2)
DEBUG | 02:27:26 194 [Router] generating implicit ack
DEBUG | 02:27:26 194 [Router] Partially randomized packet id 1250687812
DEBUG | 02:27:26 194 [Router] Enqueued local (id=0x4a8bfb44 fr=0xa4 to=0xa4, WantAck=0, HopLim=7 Ch=0x1 Portnum=5 requestId=d7c0a743 rxtime=1726626446 priority=120)
DEBUG | 02:27:26 194 [Router] Found existing packet record for fr=0x25c0dba4,to=0x1c2cbfd8,id=0xd7c0a743
DEBUG | 02:27:26 194 [Router] Found existing packet record for fr=0x25c0dba4,to=0x1c2cbfd8,id=0xd7c0a743
DEBUG | 02:27:26 194 [Router] Add packet record (id=0xd7c0a743 fr=0xa4 to=0xd8, WantAck=1, HopLim=1 Ch=0xd2 encrypted rxSNR=11.5 rxRSSI=-60 hopStart=2)
DEBUG | 02:27:26 194 [Router] Ignoring incoming msg we've already seen (id=0xd7c0a743 fr=0xa4 to=0xd8, WantAck=1, HopLim=1 Ch=0xd2 encrypted rxSNR=11.5 rxRSSI=-60 hopStart=2)
DEBUG | 02:27:26 194 [Router] cancelSending id=0xd7c0a743, removed=0
DEBUG | 02:27:26 194 [Router] Incoming message was filtered from 0x25c0dba4
DEBUG | 02:27:26 194 [Router] Rx someone rebroadcasting for us (id=0x4a8bfb44 fr=0xa4 to=0xa4, WantAck=0, HopLim=7 Ch=0x1 Portnum=5 requestId=d7c0a743 rxtime=1726626446 priority=120)
DEBUG | 02:27:26 194 [Router] didn't find pending packet
DEBUG | 02:27:26 194 [Router] Add packet record (id=0x4a8bfb44 fr=0xa4 to=0xa4, WantAck=0, HopLim=7 Ch=0x1 Portnum=5 requestId=d7c0a743 rxtime=1726626446 priority=120)
DEBUG | 02:27:26 194 [Router] handleReceived(REMOTE) (id=0x4a8bfb44 fr=0xa4 to=0xa4, WantAck=0, HopLim=7 Ch=0x1 Portnum=5 requestId=d7c0a743 rxtime=1726626446 priority=120)
DEBUG | 02:27:26 194 [Router] Module 'routing' wantsPacket=1
INFO  | 02:27:26 194 [Router] Received routing from=0x25c0dba4, id=0x4a8bfb44, portnum=5, payloadlen=2
DEBUG | 02:27:26 194 [Router] Routing sniffing (id=0x4a8bfb44 fr=0xa4 to=0xa4, WantAck=0, HopLim=7 Ch=0x1 Portnum=5 requestId=d7c0a743 rxtime=1726626446 priority=120)
DEBUG | 02:27:26 194 [Router] Received an ack for 0xd7c0a743, stopping retransmissions
DEBUG | 02:27:26 194 [Router] Delivering rx packet (id=0x4a8bfb44 fr=0xa4 to=0xa4, WantAck=0, HopLim=7 Ch=0x1 Portnum=5 requestId=d7c0a743 rxtime=1726626446 priority=120)
DEBUG | 02:27:26 194 [Router] Update DB node 0x25c0dba4, rx_time=1726626446
DEBUG | 02:27:26 194 [Router] Forwarding to phone (id=0x4a8bfb44 fr=0xa4 to=0xa4, WantAck=0, HopLim=7 Ch=0x1 Portnum=5 requestId=d7c0a743 rxtime=1726626446 priority=120)
DEBUG | 02:27:26 194 [Router] Module 'routing' considered
DEBUG | 02:27:26 195 [RadioIf] (bw=250, sf=11, cr=4/5) packet symLen=8 ms, payloadSize=29, time 452 ms
DEBUG | 02:27:26 195 [RadioIf] Lora RX (id=0x286c63d5 fr=0xd8 to=0xa4, WantAck=0, HopLim=2 Ch=0xd2 encrypted rxSNR=12.5 rxRSSI=-25 hopStart=2)
DEBUG | 02:27:26 195 [RadioIf] AirTime - Packet received : 452ms
DEBUG | 02:27:26 195 [Router] Add packet record (id=0x286c63d5 fr=0xd8 to=0xa4, WantAck=0, HopLim=2 Ch=0xd2 encrypted rxSNR=12.5 rxRSSI=-25 hopStart=2)
DEBUG | 02:27:26 195 [Router] Using channel 1 (hash 0xd2)
DEBUG | 02:27:26 195 [Router] Using AES256 key!
DEBUG | 02:27:26 195 [Router] decoded message (id=0x286c63d5 fr=0xd8 to=0xa4, WantAck=0, HopLim=2 Ch=0x1 Portnum=5 requestId=d7c0a743 rxtime=1726626446 rxSNR=12.5 rxRSSI=-25 hopStart=2)
DEBUG | 02:27:26 195 [Router] handleReceived(REMOTE) (id=0x286c63d5 fr=0xd8 to=0xa4, WantAck=0, HopLim=2 Ch=0x1 Portnum=5 requestId=d7c0a743 rxtime=1726626446 rxSNR=12.5 rxRSSI=-25 hopStar
DEBUG | 02:27:26 195 [Router] Module 'routing' wantsPacket=1
INFO  | 02:27:26 195 [Router] Received routing from=0x1c2cbfd8, id=0x286c63d5, portnum=5, payloadlen=2
DEBUG | 02:27:26 195 [Router] Routing sniffing (id=0x286c63d5 fr=0xd8 to=0xa4, WantAck=0, HopLim=2 Ch=0x1 Portnum=5 requestId=d7c0a743 rxtime=1726626446 rxSNR=12.5 rxRSSI=-25 hopStart=2)
DEBUG | 02:27:26 195 [Router] Received an ack for 0xd7c0a743, stopping retransmissions
DEBUG | 02:27:26 195 [Router] Delivering rx packet (id=0x286c63d5 fr=0xd8 to=0xa4, WantAck=0, HopLim=2 Ch=0x1 Portnum=5 requestId=d7c0a743 rxtime=1726626446 rxSNR=12.5 rxRSSI=-25 hopStart=
DEBUG | 02:27:26 195 [Router] Update DB node 0x1c2cbfd8, rx_time=1726626446
DEBUG | 02:27:26 195 [Router] Forwarding to phone (id=0x286c63d5 fr=0xd8 to=0xa4, WantAck=0, HopLim=2 Ch=0x1 Portnum=5 requestId=d7c0a743 rxtime=1726626446 rxSNR=12.5 rxRSSI=-25 hopStart=2
DEBUG | 02:27:26 195 [Router] Module 'routing' considered
DEBUG | 02:27:27 195 [RadioIf] (bw=250, sf=11, cr=4/5) packet symLen=8 ms, payloadSize=27, time 436 ms
DEBUG | 02:27:27 195 [RadioIf] Lora RX (id=0x286c63d5 fr=0xd8 to=0xa4, WantAck=0, HopLim=1 Ch=0xd2 encrypted rxSNR=11 rxRSSI=-61 hopStart=2)
DEBUG | 02:27:27 195 [RadioIf] AirTime - Packet received : 436ms
DEBUG | 02:27:27 195 [Router] Found existing packet record for fr=0x1c2cbfd8,to=0x25c0dba4,id=0x286c63d5
DEBUG | 02:27:27 195 [Router] Found existing packet record for fr=0x1c2cbfd8,to=0x25c0dba4,id=0x286c63d5
DEBUG | 02:27:27 195 [Router] Add packet record (id=0x286c63d5 fr=0xd8 to=0xa4, WantAck=0, HopLim=1 Ch=0xd2 encrypted rxSNR=11 rxRSSI=-61 hopStart=2)
DEBUG | 02:27:27 195 [Router] Ignoring incoming msg we've already seen (id=0x286c63d5 fr=0xd8 to=0xa4, WantAck=0, HopLim=1 Ch=0xd2 encrypted rxSNR=11 rxRSSI=-61 hopStart=2)
DEBUG | 02:27:27 195 [Router] cancelSending id=0x286c63d5, removed=0
DEBUG | 02:27:27 195 [Router] Incoming message was filtered from 0x1c2cbfd8
DEBUG | 02:27:32 201 [Power] Battery: usbPower=1, isCharging=1, batMv=4225, batPct=100
 *  Terminal will be reused by tasks, press any key to close it.   ```

@jp-bennett
Copy link
Collaborator

here is the output of a admin request from Android 2.4.8. Nodes are running 2.5.1 . Log is from the receiving node. DM was working prior to the admin request.

This looks like it's using a channel named "admin" rather than public key messages.

And it looks like it should have worked, too. I can see the responsea go back. Did the Android app just time out?

@thatSFguy
Copy link
Author

The error I get is NO_RESPONSE. Assuming that it's actually a timeout.

@thatSFguy
Copy link
Author

thatSFguy commented Sep 25, 2024 •
edited
Loading

It's been a while now and I have all my nodes upgraded to 2.5. I found that biting the bullet and just upgrading all the nodes and using the Security/ Admin PKI seems to work fine. Mixing and matching by trying to use the legacy admin channel is just problematic.

I do have one problem with my portduino. Somehow the web interface let me set the "managed mode" which was fine when I had the admin channel. Well, I deleted the admin channel, no Admin PK, and now I can't change any settings. Any recommendations on how to reset it to factory, since it won't let me do it via cli or web. Thanks!

@thatSFguy
Copy link
Author

To all of those that come after me. Here are some recommendations:

  1. If you upgrade to 2.5, upgrade all nodes to avoid remote admin problems
  2. The "Managed Remotely" setting in the security setting should be off. If it is on, and you remove the admin channel without updating the Remote admin key your node is locked from all config changes.
  3. Make sure you update your Admin key in the Security section by adding the Public key of the controlling node (see screeshot) to the remote admin node.
  4. Test your new administration, once working you can remove the legacy admin channel.
  5. If you locked yourself out of the node with the Remotely Managed feature you will just have to do a full erase/install. On the portduino I had to downgrade to 2.4, change the settings under device section and the upgrade again.
    Screenshot_20240925_192952_Meshtastic

I hope my experience helps someone else! Some of my issue are probably just the lack of understanding of the new features!

Thanks @jp-bennett fir all your help!

@thatSFguy
Copy link
Author

Closing this bug. If needed I can open a feature request to enhance validation on "Remotely Managed toggle" to prevent deleting the legacy admin channel if no admin key has been provided.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug Something isn't working
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
6 participants
@caveman99 @pyro2927 @garthvh @jp-bennett @slawekgajzner @thatSFguy