The logs now include SF, BW, CR, and TXP alongside RSSI/SNR on:

RX PHY, RX PHY BAD, SIM PHY DROP
RX ANNOUNCE
RX LINK
TX ANNOUNCE
TX LINKREQUEST
TX LINK
This commit is contained in:
John Poole 2026-06-04 09:30:59 -07:00
commit cfd658a4c7
5 changed files with 87 additions and 26 deletions

View file

@ -6,7 +6,17 @@ set -e
EXERCISE="/usr/local/src/microreticulum/microReticulumTbeam/exercises/204_established_identities" EXERCISE="/usr/local/src/microreticulum/microReticulumTbeam/exercises/204_established_identities"
for env in amy bob cy dan ed flo guy if [ "$#" -gt 0 ]; then
env_list=()xk
for arg in "$@"
do
env_list+=( "$(printf '%s' "$arg" | tr '[:upper:]' '[:lower:]')" )
done
else
env_list=( amy bob cy dan ed flo guy )
fi
for env in "${env_list[@]}"
do do
ENV="$(echo "$env" | tr '[:lower:]' '[:upper:]')" ENV="$(echo "$env" | tr '[:lower:]' '[:upper:]')"
local_build_dir="${EXERCISE}/.pio/build/${env}" local_build_dir="${EXERCISE}/.pio/build/${env}"

View file

@ -49,20 +49,20 @@ The unit checks the RTC and `/ex205/clock.txt` on the SD card. If the saved disc
Substantive events retain the Exercise 204 style so multi-unit log parsing can correlate TX and RX: Substantive events retain the Exercise 204 style so multi-unit log parsing can correlate TX and RX:
```text ```text
TX ANNOUNCE: Bob TX ANNOUNCE: Bob SF=7 BW=125.0 CR=4/5 TXP=14
RX PHY: phy=2 len=... RSSI=-73.5 SNR=9.2 frames=... RX PHY: phy=2 len=... RSSI=-73.5 SNR=9.2 SF=7 BW=125.0 CR=4/5 TXP=14 frames=...
RX ANNOUNCE: label=Cy hash=<destination hash> phy=Cy(2) RSSI=-73.5 SNR=9.2 RX ANNOUNCE: label=Cy hash=<destination hash> phy=Cy(2) RSSI=-73.5 SNR=9.2 SF=7 BW=125.0 CR=4/5 TXP=14
TX LINKREQUEST: opening link to Cy slot=19 attempt=1/3 TX LINKREQUEST: opening link to Cy slot=19 attempt=1/3 SF=7 BW=125.0 CR=4/5 TXP=14
LINK ACTIVE: initiator link established to Cy hash=<link hash> LINK ACTIVE: initiator link established to Cy hash=<link hash>
RX LINK: inbound link established hash=<link hash> phy=Bob(1) RSSI=-74.0 SNR=8.8 RX LINK: inbound link established hash=<link hash> phy=Bob(1) RSSI=-74.0 SNR=8.8 SF=7 BW=125.0 CR=4/5 TXP=14
TX LINK: BOB says Hi to CY iter=0 via=outbound hash=<link hash> status=2 TX LINK: BOB says Hi to CY iter=0 via=outbound hash=<link hash> status=2 SF=7 BW=125.0 CR=4/5 TXP=14
RX LINK: CY says Hi to BOB iter=0 | phy=Cy(2) RSSI=... SNR=... RX LINK: CY says Hi to BOB iter=0 | phy=Cy(2) RSSI=... SNR=... SF=7 BW=125.0 CR=4/5 TXP=14
LINK RETRY: no establishment after 60000 ms; retrying Cy attempts=1/3 LINK RETRY: no establishment after 60000 ms; retrying Cy attempts=1/3
LINK FAILED: peer=Cy attempts=3 window_ms=... waiting_for_announce=1 LINK FAILED: peer=Cy attempts=3 window_ms=... waiting_for_announce=1
LINK RETRY RESET: fresh announce from Cy LINK RETRY RESET: fresh announce from Cy
``` ```
`RX PHY` is emitted once per accepted LoRa frame before Reticulum decrypts or routes it. It is the broadest signal-strength record and includes frames that become announces, link setup packets, encrypted Link payloads, keepalives, or proofs. `RX PHY BAD` and `SIM PHY DROP` also include RSSI/SNR when malformed or intentionally blocked frames are seen. `RX PHY` is emitted once per accepted LoRa frame before Reticulum decrypts or routes it. It is the broadest signal-strength record and includes frames that become announces, link setup packets, encrypted Link payloads, keepalives, or proofs. `RX PHY BAD` and `SIM PHY DROP` also include RSSI/SNR and radio settings when malformed or intentionally blocked frames are seen. `SF`, `BW`, `CR`, and `TXP` come from the firmware build flags; transmit power is fixed by `LORA_TX_POWER_DBM` and is not dynamically changed by Exercise 205.
The following `RNS...` prefixes are generated by the linked microReticulum tree when Arduino link instrumentation is enabled: The following `RNS...` prefixes are generated by the linked microReticulum tree when Arduino link instrumentation is enabled:

View file

@ -6,7 +6,17 @@ set -e
EXERCISE="/usr/local/src/microreticulum/microReticulumTbeam/exercises/205_sustained_link" EXERCISE="/usr/local/src/microreticulum/microReticulumTbeam/exercises/205_sustained_link"
for env in amy bob cy dan ed flo guy if [ "$#" -gt 0 ]; then
env_list=()xk
for arg in "$@"
do
env_list+=( "$(printf '%s' "$arg" | tr '[:upper:]' '[:lower:]')" )
done
else
env_list=( amy bob cy dan ed flo guy )
fi
for env in "${env_list[@]}"
do do
ENV="$(echo "$env" | tr '[:lower:]' '[:upper:]')" ENV="$(echo "$env" | tr '[:lower:]' '[:upper:]')"
local_build_dir="${EXERCISE}/.pio/build/${env}" local_build_dir="${EXERCISE}/.pio/build/${env}"

View file

@ -103,11 +103,15 @@ void TBeamSupremeLoRaInterface::loop() {
_radio->startReceive(); _radio->startReceive();
return; return;
} }
Serial.printf("RX PHY: phy=%u len=%d RSSI=%.1f SNR=%.1f frames=%lu\r\n", Serial.printf("RX PHY: phy=%u len=%d RSSI=%.1f SNR=%.1f SF=%d BW=%.1f CR=4/%d TXP=%d frames=%lu\r\n",
(unsigned)physical_tx, (unsigned)physical_tx,
len, len,
_last_rssi, _last_rssi,
_last_snr, _last_snr,
(int)LORA_SF,
(double)LORA_BW_KHZ,
(int)LORA_CR,
(int)LORA_TX_POWER_DBM,
(unsigned long)_phy_rx_frames); (unsigned long)_phy_rx_frames);
if (len <= 1) { if (len <= 1) {
_radio->startReceive(); _radio->startReceive();
@ -164,20 +168,28 @@ bool TBeamSupremeLoRaInterface::unpack_frame(uint8_t* frame, int& len, uint8_t&
#if SIM_PHY_ENVELOPE #if SIM_PHY_ENVELOPE
if (len < PHY_ENVELOPE_LEN + 1) { if (len < PHY_ENVELOPE_LEN + 1) {
++_phy_bad_frames; ++_phy_bad_frames;
Serial.printf("RX PHY BAD: reason=short len=%d RSSI=%.1f SNR=%.1f bad=%lu\r\n", Serial.printf("RX PHY BAD: reason=short len=%d RSSI=%.1f SNR=%.1f SF=%d BW=%.1f CR=4/%d TXP=%d bad=%lu\r\n",
len, len,
_last_rssi, _last_rssi,
_last_snr, _last_snr,
(int)LORA_SF,
(double)LORA_BW_KHZ,
(int)LORA_CR,
(int)LORA_TX_POWER_DBM,
(unsigned long)_phy_bad_frames); (unsigned long)_phy_bad_frames);
DEBUGF("SIM PHY malformed: short frame len=%d", len); DEBUGF("SIM PHY malformed: short frame len=%d", len);
return false; return false;
} }
if (frame[0] != PHY_MAGIC_0 || frame[1] != PHY_MAGIC_1 || frame[2] != PHY_VERSION) { if (frame[0] != PHY_MAGIC_0 || frame[1] != PHY_MAGIC_1 || frame[2] != PHY_VERSION) {
++_phy_bad_frames; ++_phy_bad_frames;
Serial.printf("RX PHY BAD: reason=envelope len=%d RSSI=%.1f SNR=%.1f bad=%lu\r\n", Serial.printf("RX PHY BAD: reason=envelope len=%d RSSI=%.1f SNR=%.1f SF=%d BW=%.1f CR=4/%d TXP=%d bad=%lu\r\n",
len, len,
_last_rssi, _last_rssi,
_last_snr, _last_snr,
(int)LORA_SF,
(double)LORA_BW_KHZ,
(int)LORA_CR,
(int)LORA_TX_POWER_DBM,
(unsigned long)_phy_bad_frames); (unsigned long)_phy_bad_frames);
DEBUGF("SIM PHY malformed: bad envelope len=%d", len); DEBUGF("SIM PHY malformed: bad envelope len=%d", len);
return false; return false;
@ -185,12 +197,16 @@ bool TBeamSupremeLoRaInterface::unpack_frame(uint8_t* frame, int& len, uint8_t&
physical_tx = frame[3]; physical_tx = frame[3];
if (should_drop_physical_tx(physical_tx)) { if (should_drop_physical_tx(physical_tx)) {
++_phy_blocked_frames; ++_phy_blocked_frames;
Serial.printf("SIM PHY DROP: rx=%u tx=%u len=%d RSSI=%.1f SNR=%.1f blocked=%lu\r\n", Serial.printf("SIM PHY DROP: rx=%u tx=%u len=%d RSSI=%.1f SNR=%.1f SF=%d BW=%.1f CR=4/%d TXP=%d blocked=%lu\r\n",
(unsigned)NODE_SLOT_INDEX, (unsigned)NODE_SLOT_INDEX,
(unsigned)physical_tx, (unsigned)physical_tx,
len, len,
_last_rssi, _last_rssi,
_last_snr, _last_snr,
(int)LORA_SF,
(double)LORA_BW_KHZ,
(int)LORA_CR,
(int)LORA_TX_POWER_DBM,
(unsigned long)_phy_blocked_frames); (unsigned long)_phy_blocked_frames);
DEBUGF("SIM PHY DROP: rx=%u tx=%u len=%d", DEBUGF("SIM PHY DROP: rx=%u tx=%u len=%d",
(unsigned)NODE_SLOT_INDEX, (unsigned)NODE_SLOT_INDEX,

View file

@ -820,12 +820,16 @@ static void on_link_packet(const RNS::Bytes& data, const RNS::Packet& packet) {
float rssi = lora_impl ? lora_impl->last_rssi() : 0.0f; float rssi = lora_impl ? lora_impl->last_rssi() : 0.0f;
float snr = lora_impl ? lora_impl->last_snr() : 0.0f; float snr = lora_impl ? lora_impl->last_snr() : 0.0f;
uint8_t physical_tx = lora_impl ? lora_impl->last_physical_tx() : 255; uint8_t physical_tx = lora_impl ? lora_impl->last_physical_tx() : 255;
Serial.printf("RX LINK: %s | phy=%s(%u) RSSI=%.1f SNR=%.1f\r\n", Serial.printf("RX LINK: %s | phy=%s(%u) RSSI=%.1f SNR=%.1f SF=%d BW=%.1f CR=4/%d TXP=%d\r\n",
text.c_str(), text.c_str(),
node_label_for_slot(physical_tx), node_label_for_slot(physical_tx),
(unsigned)physical_tx, (unsigned)physical_tx,
rssi, rssi,
snr); snr,
(int)LORA_SF,
(double)LORA_BW_KHZ,
(int)LORA_CR,
(int)LORA_TX_POWER_DBM);
show_status("RX LINK", peer.c_str(), text.c_str()); show_status("RX LINK", peer.c_str(), text.c_str());
} }
@ -895,12 +899,16 @@ static void on_inbound_link_established(RNS::Link& link) {
uint8_t physical_tx = lora_impl ? lora_impl->last_physical_tx() : 255; uint8_t physical_tx = lora_impl ? lora_impl->last_physical_tx() : 255;
float rssi = lora_impl ? lora_impl->last_rssi() : 0.0f; float rssi = lora_impl ? lora_impl->last_rssi() : 0.0f;
float snr = lora_impl ? lora_impl->last_snr() : 0.0f; float snr = lora_impl ? lora_impl->last_snr() : 0.0f;
Serial.printf("RX LINK: inbound link established hash=%s phy=%s(%u) RSSI=%.1f SNR=%.1f\r\n", Serial.printf("RX LINK: inbound link established hash=%s phy=%s(%u) RSSI=%.1f SNR=%.1f SF=%d BW=%.1f CR=4/%d TXP=%d\r\n",
link.hash().toHex().c_str(), link.hash().toHex().c_str(),
node_label_for_slot(physical_tx), node_label_for_slot(physical_tx),
(unsigned)physical_tx, (unsigned)physical_tx,
rssi, rssi,
snr); snr,
(int)LORA_SF,
(double)LORA_BW_KHZ,
(int)LORA_CR,
(int)LORA_TX_POWER_DBM);
show_status("LINK ACTIVE", "inbound", link.hash().toHex().c_str()); show_status("LINK ACTIVE", "inbound", link.hash().toHex().c_str());
} }
@ -947,13 +955,17 @@ class LinkAnnounceHandler : public RNS::AnnounceHandler {
uint8_t physical_tx = lora_impl ? lora_impl->last_physical_tx() : 255; uint8_t physical_tx = lora_impl ? lora_impl->last_physical_tx() : 255;
float rssi = lora_impl ? lora_impl->last_rssi() : 0.0f; float rssi = lora_impl ? lora_impl->last_rssi() : 0.0f;
float snr = lora_impl ? lora_impl->last_snr() : 0.0f; float snr = lora_impl ? lora_impl->last_snr() : 0.0f;
Serial.printf("RX ANNOUNCE: label=%s hash=%s phy=%s(%u) RSSI=%.1f SNR=%.1f\r\n", Serial.printf("RX ANNOUNCE: label=%s hash=%s phy=%s(%u) RSSI=%.1f SNR=%.1f SF=%d BW=%.1f CR=4/%d TXP=%d\r\n",
peers[peer_index].label.c_str(), peers[peer_index].label.c_str(),
peers[peer_index].destination_hash.toHex().c_str(), peers[peer_index].destination_hash.toHex().c_str(),
node_label_for_slot(physical_tx), node_label_for_slot(physical_tx),
(unsigned)physical_tx, (unsigned)physical_tx,
rssi, rssi,
snr); snr,
(int)LORA_SF,
(double)LORA_BW_KHZ,
(int)LORA_CR,
(int)LORA_TX_POWER_DBM);
show_status("RX ANNOUNCE", peers[peer_index].label.c_str(), peers[peer_index].destination_hash.toHex().c_str()); show_status("RX ANNOUNCE", peers[peer_index].label.c_str(), peers[peer_index].destination_hash.toHex().c_str());
} }
}; };
@ -965,7 +977,7 @@ static void print_config() {
Serial.printf("Pins: CS=%d DIO1=%d RST=%d BUSY=%d SCK=%d MISO=%d MOSI=%d\r\n", Serial.printf("Pins: CS=%d DIO1=%d RST=%d BUSY=%d SCK=%d MISO=%d MOSI=%d\r\n",
(int)LORA_CS, (int)LORA_DIO1, (int)LORA_RESET, (int)LORA_BUSY, (int)LORA_CS, (int)LORA_DIO1, (int)LORA_RESET, (int)LORA_BUSY,
(int)LORA_SCK, (int)LORA_MISO, (int)LORA_MOSI); (int)LORA_SCK, (int)LORA_MISO, (int)LORA_MOSI);
Serial.printf("LoRa: freq=%.1f BW=%.1f SF=%d CR=%d sync=0x%02x txp=%d\r\n", Serial.printf("LoRa: freq=%.1f BW=%.1f SF=%d CR=4/%d sync=0x%02x TXP=%d\r\n",
(double)LORA_FREQ_MHZ, (double)LORA_BW_KHZ, (int)LORA_SF, (double)LORA_FREQ_MHZ, (double)LORA_BW_KHZ, (int)LORA_SF,
(int)LORA_CR, (int)LORA_SYNC_WORD, (int)LORA_TX_POWER_DBM); (int)LORA_CR, (int)LORA_SYNC_WORD, (int)LORA_TX_POWER_DBM);
Serial.printf("Sim: phy_envelope=%d phy_block_bob_cy=%d node_slot=%d rns_log=warning linkfwd_delay_ms=%u transport=1\r\n", Serial.printf("Sim: phy_envelope=%d phy_block_bob_cy=%d node_slot=%d rns_log=warning linkfwd_delay_ms=%u transport=1\r\n",
@ -982,7 +994,12 @@ static void send_announce() {
if (!inbound_destination || !clock_ready) { if (!inbound_destination || !clock_ready) {
return; return;
} }
Serial.printf("TX ANNOUNCE: %s\r\n", NODE_LABEL); Serial.printf("TX ANNOUNCE: %s SF=%d BW=%.1f CR=4/%d TXP=%d\r\n",
NODE_LABEL,
(int)LORA_SF,
(double)LORA_BW_KHZ,
(int)LORA_CR,
(int)LORA_TX_POWER_DBM);
show_status("TX ANNOUNCE", NODE_LABEL); show_status("TX ANNOUNCE", NODE_LABEL);
inbound_destination.announce(RNS::bytesFromString(NODE_LABEL)); inbound_destination.announce(RNS::bytesFromString(NODE_LABEL));
} }
@ -1112,11 +1129,15 @@ static void maybe_open_link(const DateTime& rtc_now, bool have_rtc_now) {
} }
++peer.outbound_attempts; ++peer.outbound_attempts;
Serial.printf("TX LINKREQUEST: opening link to %s slot=%u attempt=%u/%u\r\n", Serial.printf("TX LINKREQUEST: opening link to %s slot=%u attempt=%u/%u SF=%d BW=%.1f CR=4/%d TXP=%d\r\n",
peer.label.c_str(), peer.label.c_str(),
(unsigned)open_second, (unsigned)open_second,
(unsigned)peer.outbound_attempts, (unsigned)peer.outbound_attempts,
(unsigned)LINK_MAX_ATTEMPTS_PER_WINDOW); (unsigned)LINK_MAX_ATTEMPTS_PER_WINDOW,
(int)LORA_SF,
(double)LORA_BW_KHZ,
(int)LORA_CR,
(int)LORA_TX_POWER_DBM);
show_status("TX LINKREQ", peer.label.c_str()); show_status("TX LINKREQ", peer.label.c_str());
peer.outbound_link = RNS::Link(peer.destination); peer.outbound_link = RNS::Link(peer.destination);
peer.outbound_link.set_packet_callback(on_link_packet); peer.outbound_link.set_packet_callback(on_link_packet);
@ -1255,11 +1276,15 @@ void loop() {
peer.last_tx_ms = now; peer.last_tx_ms = now;
const char* recipient = board_id_for_label(peer.label); const char* recipient = board_id_for_label(peer.label);
String message = String(BOARD_ID) + " says Hi to " + recipient + " iter=" + String(peer.tx_iter++); String message = String(BOARD_ID) + " says Hi to " + recipient + " iter=" + String(peer.tx_iter++);
Serial.printf("TX LINK: %s via=%s hash=%s status=%u\r\n", Serial.printf("TX LINK: %s via=%s hash=%s status=%u SF=%d BW=%.1f CR=4/%d TXP=%d\r\n",
message.c_str(), message.c_str(),
link == &peer.outbound_link ? "outbound" : "inbound", link == &peer.outbound_link ? "outbound" : "inbound",
link->hash().toHex().c_str(), link->hash().toHex().c_str(),
(unsigned)link->status()); (unsigned)link->status(),
(int)LORA_SF,
(double)LORA_BW_KHZ,
(int)LORA_CR,
(int)LORA_TX_POWER_DBM);
show_status("TX LINK", peer.label.c_str(), message.c_str()); show_status("TX LINK", peer.label.c_str(), message.c_str());
RNS::Packet(*link, RNS::bytesFromString(message.c_str())).send(); RNS::Packet(*link, RNS::bytesFromString(message.c_str())).send();
delay(120); delay(120);