Skip to content

BUG: --request-telemetry on a distant node times out the first time, then it works #874

Open
Open
BUG: --request-telemetry on a distant node times out the first time, then it works#874

Description

@juergenRe
juergenRe
opened on Dec 4, 2025

Somehow weird behavior:

  1. Start-up node x, wait a few minutes, then --request-telemetry --dest <y>: here I do not get a response and the request times out
  2. After time-out or aborting command after ca. 15s: retr the same command: now the desired result is shown.
  3. After waiting a few minutes, points 1 and 2 repeat.

Both nodes are in hop=0 distance, one is a RAK, the other is a Heltec V3 connected over WLAN (but I believe so far, that it will have the same behavior when connected via serial).

When connecting directly to node (over serial line), the request is always answered immediately.

Activity

  1. juergenRe commented on Dec 8, 2025

    @juergenRe
    juergenRe
    on Dec 8, 2025
    Author

    Doing some tests on this revealed this:

    Reading fails: log file "TelemetryRequestFailed_afterWait-2.log"

    1. CLI will always send a packet to the radio requesting the data:
    Connected to radio
Sending environment_metrics telemetry request to !c5db8a75 on channelIndex:0 (this could take a while)
DEBUG file:mesh_interface.py sendData line:544 Serializing protobuf as data: environment_metrics { }
DEBUG file:mesh_interface.py sendData line:547 len(data): 2
DEBUG file:mesh_interface.py sendData line:548 mesh_pb2.Constants.DATA_PAYLOAD_LEN: 233
DEBUG file:mesh_interface.py sendData line:571 Setting a response handler for requestId 1271786526
DEBUG file:mesh_interface.py _sendPacket line:1010 Sending packet: to: 3319499381 decoded { portnum: TELEMETRY_APP payload: "\032\000" want_response: true } id: 1271786526 hop_limit: 3 priority: RELIABLE
DEBUG file:stream_interface.py _sendToRadioImpl line:124 Sending: TS: 2025-12-08T11:00:24.524575 packet { to: 3319499381 decoded { portnum: TELEMETRY_APP payload: "\032\000" want_response: true } id: 1271786526 hop_limit: 3 priority: RELIABLE }
    1. it seems to me that the packet has arrived in the radio - the queue contains this message id:
    DEBUG file:mesh_interface.py _handleFromRadio line:1308 Received from radio: queueStatus {
  free: 15
  maxlen: 16
  mesh_packet_id: 2156626112
}
    1. In case the communication fails, there is no further packet received with the ID (here: 1271786526).
    2. But later on (after 4mins) the radio may respond, but with a different ID (2671751758, timestamp 2025-12-08T11:04:48.699962). In other cases there is no response with environmental data at all.

    Reading succeeds: log file "TelemetryRequestSucceeded_afterWait.log"

    1. Sending log is the same as when it fails till feedback from the queue.
    2. In case of success, the radio sends this:
    DEBUG file:mesh_interface.py _handleFromRadio line:1296 in mesh_interface.py _handleFromRadio() TS: 2025-12-08T11:07:30.275885 fromRadioBytes: b'\x12d\ru\x8a\xdb\xc5\x15\x08l)\xdb"\x1c\x08C\x12\x11\r]\xa36i\x1a\n\r)\\\xbdA\x1d1\x80rD5\xc0\x80\x8b\x80H\x005Obq\xb6=`\xa36iE\x00\x00\xb8@H\x02x\x02\x82\x01 \x85\xed\xcav\x83\x96\x18\x00R\x93\x93-\x8c\xd21\x9e\x15\x12\xec\xf4\xe3!\xb8\x87\xe0[\x14iq\x82\rU\x88\x01\x01\x98\x01u'
DEBUG file:mesh_interface.py _handleFromRadio line:1308 Received from radio: packet {
  from: 3319499381
  to: 3676924936
  decoded {
    portnum: TELEMETRY_APP
    payload: "\r]\2436i\032\n\r)\\275A\0351\200rD"
    request_id: 2156626112
    bitfield: 0
  }
  id: 3060884047
  rx_time: 1765188448
  rx_snr: 5.75
  hop_limit: 2
  hop_start: 2
  public_key: "\205\355\312v\203\226\030\000R\223\223-\214\3221\236\025\022\354\364\343!\270\207\340[\024iq\202\rU"
  pki_encrypted: true
  relay_node: 117
}

    Now the CLI can associate the pending request with this response using the message ID and everything terminates as expected.

    From the log I believe there is some mix-up of messages in the radio itself. When the communication fails, it seems to me that there are also a lot of other telemetry packets sent from the radio and it might be that there is a race condition in answering the requests.

    A possible workaround might be that the CLI resends the request after the timeout, but this is also dangerous because it might congest the communication channel.

    Environment used:

    FW: 2.6.11.60ec05e on both devices
    CLI: 2.7.3
    HW: RAK4630 with BMP280; HelTec V3 connected via serial port

    TelemetryRequestFailed_afterWait-2.log
    TelemetryRequestSucceeded_afterWait.log

  2. rjDipcord commented on Dec 9, 2025

    @rjDipcord
    rjDipcord
    on Dec 9, 2025

    Are you seeing that when you send a --request-telemetry command with a specific destination, you can see the a packet which fits that criteria? Are you by chance seeing that a --request-telemetry command sent disobeys the --dest flag, and instead just sends a TELEMETRY_APP packet to broadcast from the sender?

    Please let me know, because this is the behavior I am witnessing and I need to know if it's related or should have a new bug report filed.

  3. juergenRe commented on Dec 10, 2025

    @juergenRe
    juergenRe
    on Dec 10, 2025
    Author

    Yes, I send to a specific node and the CLI ask the data from this node. In the first log example you can see the request going from the local node to !c5db8a75 = 3319499381.

    For all logs I have been looking into, this was always the case. So no broadcast. BTW, I noticed such "lost messages" also for other commands, especially for the --configure.

    I would like to see in more detail whats going on inside the radio. Can I switch on some addional logging over a serial line or something like that? Where do I have to look for this?

  4. juergenRe commented on Dec 11, 2025

    @juergenRe
    juergenRe
    on Dec 11, 2025
    Author

    The issue is not that simple to reproduce as I thought. In the meantime I found more symptoms:

    1. I did some reconfiguration from network access back to bluetooth, then the device was sitting around for one day, collecting other nodes during that time. When I was retrying telemetry this morning, it worked always. But - strange enough - the node was rebooting each time the request was answered.
    2. Changing back to network access did not change this.
    3. Did a factory reset followed by a reconfiguration with network. Telemetry now does not work consistently. When time-out occurs or I abort the request, a reboot of the radio I connected to (not the node I ask the telemetry) does a reboot.

    All this with the same SW settings as described above.

  5. roberthadow commented on Aug 3, 2026

    @roberthadow
    roberthadow
    on Aug 3, 2026

    @juergenRe --

    You say, "Telemetry now does not work consistently. " I agree. I have a stable of six Heltec devices. I use the same script to configure all of them. I don't touch any Module attributes; they are all default. Nevertheless, telemettry works on some devices sometimes and on others, never. I haven't touched any Telemetry configuration elements or Power Saving elements. There is no reason I should be able to poll a device using admin successfully, then get a timeout when I ask for telemetry.

    I have a test script that exercises functions in turn. It establishes first that each device has WiFi connectivity, then that evey device has a valid public key, then that every device has a valid entry for every other device in its nodelist, The script tests sendtext operation to named devices with ack, It verifies that every administered node has valid admin keys. Then it tests that simple admin commands work over LoRa. All good so far. Then it asks for telemetry.

    When a device falls off the wagon, as you might appreciate, it takes takes either work or time to get the orchestra back in tune and in time. Once everything is right again, I have a script that exercises the telemetry function as a means of monitoring battery voltage. Performance is disappointing. Here is a run from last night:

    DASHBOARD Last reported condition   Cumulative successful reads
NODE  WiFi  LoRa    Battery Volts   WiFi  LoRa  Battery (telemetry)
A658  TRUE  FALSE   NA              20     1     1
BB38  TRUE  TRUE    4.19            19     13     13
B4F8  TRUE  FALSE   NA              20     12     12
02D4  TRUE  FALSE   NA              20     0     0
4524  TRUE  TRUE    4.36            1     1     1
60C0  TRUE  FALSE   NA              20     4     4
 
Mon Aug  3 08:49:30 AM EDT 2026
 
Mon Aug  3 08:49:30 AM EDT 2026
dashFile =    ./results/test.dash.20260803084930.txt
Total execution time: 32032 seconds.

    In this test, I didn't ever expect 02D4 to deliver. It is the adminstering node. Meshtastic supports loopback (messages sent to self), but does not allow a node to query itself over admin (LoRa). I let the battery die on 4523, but reconnected it to power just before the test ended. You'll notice that the test took nine hours. A timeout takes a long time to fail.

    A review of the entire test showed only one broken pipe error. The rest of the failures were all timeouts. For me, that's basically failing silently. I get no useful troubleshooting information. Gemini isn't much help either. Its list of possible failure points is long and vague.

    What has been your recent experience?

  6. juergenRe commented on Aug 4, 2026

    @juergenRe
    juergenRe
    on Aug 4, 2026
    Author

    I haven't been working on it since then, was switching to other stuff in the meantime.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions