Throttle hot-path debug logging for sender stability

This commit is contained in:
2026-02-17 01:15:35 +01:00
parent d7b5bb0f0b
commit e0f3ffc21c
2 changed files with 14 additions and 35 deletions

View File

@@ -66,17 +66,10 @@ bool lora_send(const LoraPacket &pkt) {
return true;
}
uint32_t t0 = 0;
uint32_t t1 = 0;
uint32_t t2 = 0;
uint32_t t3 = 0;
uint32_t t4 = 0;
if (SERIAL_DEBUG_MODE) {
t0 = millis();
}
LoRa.idle();
if (SERIAL_DEBUG_MODE) {
t1 = millis();
}
uint8_t buffer[1 + 2 + LORA_MAX_PAYLOAD + 2];
size_t idx = 0;
buffer[idx++] = static_cast<uint8_t>(pkt.msg_kind);
@@ -95,25 +88,19 @@ bool lora_send(const LoraPacket &pkt) {
buffer[idx++] = static_cast<uint8_t>(crc & 0xFF);
LoRa.beginPacket();
if (SERIAL_DEBUG_MODE) {
t2 = millis();
}
LoRa.write(buffer, idx);
if (SERIAL_DEBUG_MODE) {
t3 = millis();
}
int result = LoRa.endPacket(false);
bool ok = result == 1;
if (SERIAL_DEBUG_MODE) {
t4 = millis();
Serial.printf("lora_tx: idle=%lums begin=%lums write=%lums end=%lums total=%lums len=%u\n",
static_cast<unsigned long>(t1 - t0),
static_cast<unsigned long>(t2 - t1),
static_cast<unsigned long>(t3 - t2),
static_cast<unsigned long>(t4 - t3),
static_cast<unsigned long>(t4 - t0),
static_cast<unsigned>(idx));
uint32_t tx_ms = millis() - t0;
if (!ok || tx_ms > 2000) {
Serial.printf("lora_tx: len=%u total=%lums ok=%u\n",
static_cast<unsigned>(idx),
static_cast<unsigned long>(tx_ms),
ok ? 1U : 0U);
}
}
return result == 1;
return ok;
}
bool lora_receive(LoraPacket &pkt, uint32_t timeout_ms) {

View File

@@ -106,6 +106,7 @@ static uint32_t g_sender_ack_retry_total = 0;
static uint32_t g_sender_ack_rtt_last_ms = 0;
static uint32_t g_sender_ack_rtt_ewma_ms = 0;
static uint32_t g_sender_ack_miss_streak = 0;
static uint32_t g_last_ack_window_log_ms = 0;
static RxRejectReason g_sender_rx_reject_reason = RxRejectReason::None;
static uint32_t g_sender_rx_reject_log_ms = 0;
static RxRejectReason g_receiver_rx_reject_reason = RxRejectReason::None;
@@ -813,7 +814,7 @@ static bool send_batch_payload(const uint8_t *data, size_t len, uint32_t ts_for_
note_fault(g_sender_faults, g_sender_last_error, g_sender_last_error_utc, g_sender_last_error_ms, FaultType::LoraTx);
display_set_last_error(g_sender_last_error, g_sender_last_error_utc, g_sender_last_error_ms);
}
if (SERIAL_DEBUG_MODE && tx_ms > 500) {
if (SERIAL_DEBUG_MODE && (!ok || tx_ms > 2000)) {
serial_debug_printf("tx: chunk %u/%u took %lums ok=%u", static_cast<unsigned>(i + 1),
static_cast<unsigned>(chunk_count), static_cast<unsigned long>(tx_ms), ok ? 1 : 0);
}
@@ -1345,17 +1346,7 @@ static void sender_loop() {
data.valid = has_snapshot;
bool appended = append_meter_sample(data, meter_ok, has_snapshot);
if (SERIAL_DEBUG_MODE) {
serial_debug_printf("sample: i=%lu ok=%u appended=%u e_kwh=%.3f p1=%.1f p2=%.1f p3=%.1f ms=%lu",
static_cast<unsigned long>(g_build_attempts),
meter_ok ? 1U : 0U,
appended ? 1U : 0U,
static_cast<double>(data.energy_total_kwh),
static_cast<double>(data.phase_power_w[0]),
static_cast<double>(data.phase_power_w[1]),
static_cast<double>(data.phase_power_w[2]),
static_cast<unsigned long>(now_ms));
}
(void)appended;
display_set_last_meter(data);
display_set_last_read(meter_ok, data.ts_utc);
}
@@ -1412,7 +1403,8 @@ static void sender_loop() {
if (ack_window_second_ms > 5000) {
ack_window_second_ms = 5000;
}
if (SERIAL_DEBUG_MODE) {
if (SERIAL_DEBUG_MODE && (g_sender_ack_miss_streak > 0 || now_ms - g_last_ack_window_log_ms >= 10000)) {
g_last_ack_window_log_ms = now_ms;
serial_debug_printf("ack: rx windows=%lu/%lu airtime=%lu miss_streak=%lu",
static_cast<unsigned long>(ack_window_first_ms),
static_cast<unsigned long>(ack_window_second_ms),