diff --git a/src/Power.cpp b/src/Power.cpp index 6ed937648b..2f5f441ae3 100644 --- a/src/Power.cpp +++ b/src/Power.cpp @@ -971,7 +971,6 @@ bool Power::axpChipInit() PMU->enableVbusVoltageMeasure(); PMU->enableBattVoltageMeasure(); - LOG_DEBUG("=======================================================================\n"); if (PMU->isChannelAvailable(XPOWERS_DCDC1)) { LOG_DEBUG("DC1 : %s Voltage:%u mV \n", PMU->isPowerChannelEnable(XPOWERS_DCDC1) ? "+" : "-", PMU->getPowerChannelVoltage(XPOWERS_DCDC1)); @@ -1020,7 +1019,6 @@ bool Power::axpChipInit() LOG_DEBUG("BLDO2: %s Voltage:%u mV \n", PMU->isPowerChannelEnable(XPOWERS_BLDO2) ? "+" : "-", PMU->getPowerChannelVoltage(XPOWERS_BLDO2)); } - LOG_DEBUG("=======================================================================\n"); // We can safely ignore this approach for most (or all) boards because MCU turned off // earlier than battery discharged to 2.6V. diff --git a/src/airtime.cpp b/src/airtime.cpp index 2702ee2bf6..fcda054682 100644 --- a/src/airtime.cpp +++ b/src/airtime.cpp @@ -13,17 +13,17 @@ void AirTime::logAirtime(reportTypes reportType, uint32_t airtime_ms) { if (reportType == TX_LOG) { - LOG_DEBUG("AirTime - Packet transmitted : %ums\n", airtime_ms); + LOG_DEBUG("Packet transmitted : %ums\n", airtime_ms); this->airtimes.periodTX[0] = this->airtimes.periodTX[0] + airtime_ms; air_period_tx[0] = air_period_tx[0] + airtime_ms; this->utilizationTX[this->getPeriodUtilHour()] = this->utilizationTX[this->getPeriodUtilHour()] + airtime_ms; } else if (reportType == RX_LOG) { - LOG_DEBUG("AirTime - Packet received : %ums\n", airtime_ms); + LOG_DEBUG("Packet received : %ums\n", airtime_ms); this->airtimes.periodRX[0] = this->airtimes.periodRX[0] + airtime_ms; air_period_rx[0] = air_period_rx[0] + airtime_ms; } else if (reportType == RX_ALL_LOG) { - LOG_DEBUG("AirTime - Packet received (noise?) : %ums\n", airtime_ms); + LOG_DEBUG("Packet received (noise?) : %ums\n", airtime_ms); this->airtimes.periodRX_ALL[0] = this->airtimes.periodRX_ALL[0] + airtime_ms; } diff --git a/src/gps/GPS.cpp b/src/gps/GPS.cpp index f2b15ba784..33c21c5bbe 100644 --- a/src/gps/GPS.cpp +++ b/src/gps/GPS.cpp @@ -530,23 +530,23 @@ bool GPS::setup() _serial_gps->write("$PAIR513*3D\r\n"); // save configuration } else if (gnssModel == GNSS_MODEL_UBLOX6) { clearBuffer(); - SEND_UBX_PACKET(0x06, 0x02, _message_DISABLE_TXT_INFO, "Unable to disable text info messages.\n", 500); - SEND_UBX_PACKET(0x06, 0x39, _message_JAM_6_7, "Unable to enable interference resistance.\n", 500); - SEND_UBX_PACKET(0x06, 0x23, _message_NAVX5, "Unable to configure NAVX5 settings.\n", 500); + SEND_UBX_PACKET(0x06, 0x02, _message_DISABLE_TXT_INFO, "disable text info messages", 500); + SEND_UBX_PACKET(0x06, 0x39, _message_JAM_6_7, "enable interference resistance", 500); + SEND_UBX_PACKET(0x06, 0x23, _message_NAVX5, "configure NAVX5 settings", 500); // Turn off unwanted NMEA messages, set update rate - SEND_UBX_PACKET(0x06, 0x08, _message_1HZ, "Unable to set GPS update rate.\n", 500); - SEND_UBX_PACKET(0x06, 0x01, _message_GLL, "Unable to disable NMEA GLL.\n", 500); - SEND_UBX_PACKET(0x06, 0x01, _message_GSA, "Unable to Enable NMEA GSA.\n", 500); - SEND_UBX_PACKET(0x06, 0x01, _message_GSV, "Unable to disable NMEA GSV.\n", 500); - SEND_UBX_PACKET(0x06, 0x01, _message_VTG, "Unable to disable NMEA VTG.\n", 500); - SEND_UBX_PACKET(0x06, 0x01, _message_RMC, "Unable to enable NMEA RMC.\n", 500); - SEND_UBX_PACKET(0x06, 0x01, _message_GGA, "Unable to enable NMEA GGA.\n", 500); + SEND_UBX_PACKET(0x06, 0x08, _message_1HZ, "set GPS update rate", 500); + SEND_UBX_PACKET(0x06, 0x01, _message_GLL, "disable NMEA GLL", 500); + SEND_UBX_PACKET(0x06, 0x01, _message_GSA, "enable NMEA GSA", 500); + SEND_UBX_PACKET(0x06, 0x01, _message_GSV, "disable NMEA GSV", 500); + SEND_UBX_PACKET(0x06, 0x01, _message_VTG, "disable NMEA VTG", 500); + SEND_UBX_PACKET(0x06, 0x01, _message_RMC, "enable NMEA RMC", 500); + SEND_UBX_PACKET(0x06, 0x01, _message_GGA, "enable NMEA GGA", 500); clearBuffer(); - SEND_UBX_PACKET(0x06, 0x11, _message_CFG_RXM_ECO, "Unable to enable powersaving ECO mode for Neo-6.\n", 500); - SEND_UBX_PACKET(0x06, 0x3B, _message_CFG_PM2, "Unable to enable powersaving details for GPS.\n", 500); - SEND_UBX_PACKET(0x06, 0x01, _message_AID, "Unable to disable UBX-AID.\n", 500); + SEND_UBX_PACKET(0x06, 0x11, _message_CFG_RXM_ECO, "enable powersaving ECO mode for Neo-6", 500); + SEND_UBX_PACKET(0x06, 0x3B, _message_CFG_PM2, "enable powersaving details for GPS", 500); + SEND_UBX_PACKET(0x06, 0x01, _message_AID, "disable UBX-AID", 500); msglen = makeUBXPacket(0x06, 0x09, sizeof(_message_SAVE), _message_SAVE); _serial_gps->write(UBXscratch, msglen); @@ -567,7 +567,7 @@ bool GPS::setup() if (getACK(0x06, 0x3e, 800) == GNSS_RESPONSE_NAK) { // It's not critical if the module doesn't acknowledge this configuration. - LOG_INFO("Unable to reconfigure GNSS - defaults maintained. Is this module GPS-only?\n"); + LOG_INFO("reconfigure GNSS - defaults maintained. Is this module GPS-only?\n"); } else { if (gnssModel == GNSS_MODEL_UBLOX7) { LOG_INFO("GNSS configured for GPS+SBAS.\n"); @@ -581,40 +581,40 @@ bool GPS::setup() // Disable Text Info messages //6,7,8,9 clearBuffer(); - SEND_UBX_PACKET(0x06, 0x02, _message_DISABLE_TXT_INFO, "Unable to disable text info messages.\n", 500); + SEND_UBX_PACKET(0x06, 0x02, _message_DISABLE_TXT_INFO, "disable text info messages", 500); if (gnssModel == GNSS_MODEL_UBLOX8) { // 8 clearBuffer(); - SEND_UBX_PACKET(0x06, 0x39, _message_JAM_8, "Unable to enable interference resistance.\n", 500); + SEND_UBX_PACKET(0x06, 0x39, _message_JAM_8, "enable interference resistance", 500); clearBuffer(); - SEND_UBX_PACKET(0x06, 0x23, _message_NAVX5_8, "Unable to configure NAVX5_8 settings.\n", 500); + SEND_UBX_PACKET(0x06, 0x23, _message_NAVX5_8, "configure NAVX5_8 settings", 500); } else { // 6,7,9 - SEND_UBX_PACKET(0x06, 0x39, _message_JAM_6_7, "Unable to enable interference resistance.\n", 500); - SEND_UBX_PACKET(0x06, 0x23, _message_NAVX5, "Unable to configure NAVX5 settings.\n", 500); + SEND_UBX_PACKET(0x06, 0x39, _message_JAM_6_7, "enable interference resistance", 500); + SEND_UBX_PACKET(0x06, 0x23, _message_NAVX5, "configure NAVX5 settings", 500); } // Turn off unwanted NMEA messages, set update rate - SEND_UBX_PACKET(0x06, 0x08, _message_1HZ, "Unable to set GPS update rate.\n", 500); - SEND_UBX_PACKET(0x06, 0x01, _message_GLL, "Unable to disable NMEA GLL.\n", 500); - SEND_UBX_PACKET(0x06, 0x01, _message_GSA, "Unable to Enable NMEA GSA.\n", 500); - SEND_UBX_PACKET(0x06, 0x01, _message_GSV, "Unable to disable NMEA GSV.\n", 500); - SEND_UBX_PACKET(0x06, 0x01, _message_VTG, "Unable to disable NMEA VTG.\n", 500); - SEND_UBX_PACKET(0x06, 0x01, _message_RMC, "Unable to enable NMEA RMC.\n", 500); - SEND_UBX_PACKET(0x06, 0x01, _message_GGA, "Unable to enable NMEA GGA.\n", 500); + SEND_UBX_PACKET(0x06, 0x08, _message_1HZ, "set GPS update rate", 500); + SEND_UBX_PACKET(0x06, 0x01, _message_GLL, "disable NMEA GLL", 500); + SEND_UBX_PACKET(0x06, 0x01, _message_GSA, "enable NMEA GSA", 500); + SEND_UBX_PACKET(0x06, 0x01, _message_GSV, "disable NMEA GSV", 500); + SEND_UBX_PACKET(0x06, 0x01, _message_VTG, "disable NMEA VTG", 500); + SEND_UBX_PACKET(0x06, 0x01, _message_RMC, "enable NMEA RMC", 500); + SEND_UBX_PACKET(0x06, 0x01, _message_GGA, "enable NMEA GGA", 500); if (uBloxProtocolVersion >= 18) { clearBuffer(); - SEND_UBX_PACKET(0x06, 0x86, _message_PMS, "Unable to enable powersaving for GPS.\n", 500); - SEND_UBX_PACKET(0x06, 0x3B, _message_CFG_PM2, "Unable to enable powersaving details for GPS.\n", 500); + SEND_UBX_PACKET(0x06, 0x86, _message_PMS, "enable powersaving for GPS", 500); + SEND_UBX_PACKET(0x06, 0x3B, _message_CFG_PM2, "enable powersaving details for GPS", 500); // For M8 we want to enable NMEA vserion 4.10 so we can see the additional sats. if (gnssModel == GNSS_MODEL_UBLOX8) { clearBuffer(); - SEND_UBX_PACKET(0x06, 0x17, _message_NMEA, "Unable to enable NMEA 4.10.\n", 500); + SEND_UBX_PACKET(0x06, 0x17, _message_NMEA, "enable NMEA 4.10", 500); } } else { - SEND_UBX_PACKET(0x06, 0x11, _message_CFG_RXM_PSM, "Unable to enable powersaving mode for GPS.\n", 500); - SEND_UBX_PACKET(0x06, 0x3B, _message_CFG_PM2, "Unable to enable powersaving details for GPS.\n", 500); + SEND_UBX_PACKET(0x06, 0x11, _message_CFG_RXM_PSM, "enable powersaving mode for GPS", 500); + SEND_UBX_PACKET(0x06, 0x3B, _message_CFG_PM2, "enable powersaving details for GPS", 500); } msglen = makeUBXPacket(0x06, 0x09, sizeof(_message_SAVE), _message_SAVE); @@ -627,40 +627,38 @@ bool GPS::setup() } else if (gnssModel == GNSS_MODEL_UBLOX10) { delay(1000); clearBuffer(); - SEND_UBX_PACKET(0x06, 0x8A, _message_VALSET_DISABLE_NMEA_RAM, "Unable to disable NMEA messages in M10 RAM.\n", 300); + SEND_UBX_PACKET(0x06, 0x8A, _message_VALSET_DISABLE_NMEA_RAM, "disable NMEA messages in M10 RAM", 300); delay(750); clearBuffer(); - SEND_UBX_PACKET(0x06, 0x8A, _message_VALSET_DISABLE_NMEA_BBR, "Unable to disable NMEA messages in M10 BBR.\n", 300); + SEND_UBX_PACKET(0x06, 0x8A, _message_VALSET_DISABLE_NMEA_BBR, "disable NMEA messages in M10 BBR", 300); delay(750); clearBuffer(); - SEND_UBX_PACKET(0x06, 0x8A, _message_VALSET_DISABLE_TXT_INFO_RAM, - "Unable to disable Info messages for M10 GPS RAM.\n", 300); + SEND_UBX_PACKET(0x06, 0x8A, _message_VALSET_DISABLE_TXT_INFO_RAM, "disable Info messages for M10 GPS RAM", 300); delay(750); // Next disable Info txt messages in BBR layer clearBuffer(); - SEND_UBX_PACKET(0x06, 0x8A, _message_VALSET_DISABLE_TXT_INFO_BBR, - "Unable to disable Info messages for M10 GPS BBR.\n", 300); + SEND_UBX_PACKET(0x06, 0x8A, _message_VALSET_DISABLE_TXT_INFO_BBR, "disable Info messages for M10 GPS BBR", 300); delay(750); // Do M10 configuration for Power Management. - SEND_UBX_PACKET(0x06, 0x8A, _message_VALSET_PM_RAM, "Unable to enable powersaving for M10 GPS RAM.\n", 300); + SEND_UBX_PACKET(0x06, 0x8A, _message_VALSET_PM_RAM, "enable powersaving for M10 GPS RAM", 300); delay(750); - SEND_UBX_PACKET(0x06, 0x8A, _message_VALSET_PM_BBR, "Unable to enable powersaving for M10 GPS BBR.\n", 300); + SEND_UBX_PACKET(0x06, 0x8A, _message_VALSET_PM_BBR, "enable powersaving for M10 GPS BBR", 300); delay(750); - SEND_UBX_PACKET(0x06, 0x8A, _message_VALSET_ITFM_RAM, "Unable to enable Jamming detection M10 GPS RAM.\n", 300); + SEND_UBX_PACKET(0x06, 0x8A, _message_VALSET_ITFM_RAM, "enable Jamming detection M10 GPS RAM", 300); delay(750); - SEND_UBX_PACKET(0x06, 0x8A, _message_VALSET_ITFM_BBR, "Unable to enable Jamming detection M10 GPS BBR.\n", 300); + SEND_UBX_PACKET(0x06, 0x8A, _message_VALSET_ITFM_BBR, "enable Jamming detection M10 GPS BBR", 300); delay(750); // Here is where the init commands should go to do further M10 initialization. - SEND_UBX_PACKET(0x06, 0x8A, _message_VALSET_DISABLE_SBAS_RAM, "Unable to disable SBAS M10 GPS RAM.\n", 300); + SEND_UBX_PACKET(0x06, 0x8A, _message_VALSET_DISABLE_SBAS_RAM, "disable SBAS M10 GPS RAM", 300); delay(750); // will cause a receiver restart so wait a bit - SEND_UBX_PACKET(0x06, 0x8A, _message_VALSET_DISABLE_SBAS_BBR, "Unable to disable SBAS M10 GPS BBR.\n", 300); + SEND_UBX_PACKET(0x06, 0x8A, _message_VALSET_DISABLE_SBAS_BBR, "disable SBAS M10 GPS BBR", 300); delay(750); // will cause a receiver restart so wait a bit // Done with initialization, Now enable wanted NMEA messages in BBR layer so they will survive a periodic sleep. - SEND_UBX_PACKET(0x06, 0x8A, _message_VALSET_ENABLE_NMEA_BBR, "Unable to enable messages for M10 GPS BBR.\n", 300); + SEND_UBX_PACKET(0x06, 0x8A, _message_VALSET_ENABLE_NMEA_BBR, "enable messages for M10 GPS BBR", 300); delay(750); // Next enable wanted NMEA messages in RAM layer - SEND_UBX_PACKET(0x06, 0x8A, _message_VALSET_ENABLE_NMEA_RAM, "Unable to enable messages for M10 GPS RAM.\n", 500); + SEND_UBX_PACKET(0x06, 0x8A, _message_VALSET_ENABLE_NMEA_RAM, "enable messages for M10 GPS RAM", 500); delay(750); // As the M10 has no flash, the best we can do to preserve the config is to set it in RAM and BBR. @@ -1073,12 +1071,15 @@ int GPS::prepareDeepSleep(void *unused) return 0; } +const char *PROBE_MESSAGE = "Trying %s (%s)...\n"; +const char *DETECTED_MESSAGE = "%s detected, using %s Module\n"; + #define PROBE_SIMPLE(CHIP, TOWRITE, RESPONSE, DRIVER, TIMEOUT, ...) \ - LOG_DEBUG("Trying " TOWRITE " (" CHIP ") ...\n"); \ + LOG_DEBUG(PROBE_MESSAGE, TOWRITE, CHIP); \ clearBuffer(); \ _serial_gps->write(TOWRITE "\r\n"); \ if (getACK(RESPONSE, TIMEOUT) == GNSS_RESPONSE_OK) { \ - LOG_INFO(CHIP " detected, using " #DRIVER " Module\n"); \ + LOG_INFO(DETECTED_MESSAGE, CHIP, #DRIVER); \ return DRIVER; \ } @@ -1367,21 +1368,21 @@ bool GPS::factoryReset() 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x02, 0x1C, 0xA2}; _serial_gps->write(_message_reset1, sizeof(_message_reset1)); if (getACK(0x05, 0x01, 10000)) { - LOG_INFO("Get ack success!\n"); + LOG_INFO(ACK_SUCCESS_MESSAGE); } delay(100); byte _message_reset2[] = {0xB5, 0x62, 0x06, 0x09, 0x0D, 0x00, 0xFF, 0xFF, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x01, 0x1B, 0xA1}; _serial_gps->write(_message_reset2, sizeof(_message_reset2)); if (getACK(0x05, 0x01, 10000)) { - LOG_INFO("Get ack success!\n"); + LOG_INFO(ACK_SUCCESS_MESSAGE); } delay(100); byte _message_reset3[] = {0xB5, 0x62, 0x06, 0x09, 0x0D, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0xFF, 0xFF, 0x00, 0x00, 0x03, 0x1D, 0xB3}; _serial_gps->write(_message_reset3, sizeof(_message_reset3)); if (getACK(0x05, 0x01, 10000)) { - LOG_INFO("Get ack success!\n"); + LOG_INFO(ACK_SUCCESS_MESSAGE); } // Reset device ram to COLDSTART state // byte _message_CFG_RST_COLDSTART[] = {0xB5, 0x62, 0x06, 0x04, 0x04, 0x00, 0xFF, 0xB9, 0x00, 0x00, 0xC6, 0x8B}; diff --git a/src/gps/GPS.h b/src/gps/GPS.h index 317d80544a..6222881bc6 100644 --- a/src/gps/GPS.h +++ b/src/gps/GPS.h @@ -156,6 +156,8 @@ class GPS : private concurrency::OSThread static const uint8_t _message_CAS_CFG_NAVX_CONF[]; static const uint8_t _message_CAS_CFG_RATE_1HZ[]; + const char *ACK_SUCCESS_MESSAGE = "Get ack success!\n"; + meshtastic_Position p = meshtastic_Position_init_default; /** This is normally bound to config.position.gps_en_gpio but some rare boards (like heltec tracker) need more advanced diff --git a/src/gps/ubx.h b/src/gps/ubx.h index c73a7efb3c..b137d3349b 100644 --- a/src/gps/ubx.h +++ b/src/gps/ubx.h @@ -1,8 +1,10 @@ +const char *failMessage = "Unable to %s\n"; + #define SEND_UBX_PACKET(TYPE, ID, DATA, ERRMSG, TIMEOUT) \ msglen = makeUBXPacket(TYPE, ID, sizeof(DATA), DATA); \ _serial_gps->write(UBXscratch, msglen); \ if (getACK(TYPE, ID, TIMEOUT) != GNSS_RESPONSE_OK) { \ - LOG_WARN(#ERRMSG); \ + LOG_WARN(failMessage, #ERRMSG); \ } // Power Management diff --git a/src/mesh/FloodingRouter.cpp b/src/mesh/FloodingRouter.cpp index fbe56159c0..e2dbd89977 100644 --- a/src/mesh/FloodingRouter.cpp +++ b/src/mesh/FloodingRouter.cpp @@ -21,7 +21,7 @@ ErrorCode FloodingRouter::send(meshtastic_MeshPacket *p) bool FloodingRouter::shouldFilterReceived(const meshtastic_MeshPacket *p) { if (wasSeenRecently(p)) { // Note: this will also add a recent packet record - printPacket("Ignoring incoming msg we've already seen", p); + printPacket("Ignoring dupe incoming msg", p); if (config.device.role != meshtastic_Config_DeviceConfig_Role_ROUTER && config.device.role != meshtastic_Config_DeviceConfig_Role_REPEATER) { // cancel rebroadcast of this message *if* there was already one, unless we're a router/repeater! @@ -38,7 +38,7 @@ void FloodingRouter::sniffReceived(const meshtastic_MeshPacket *p, const meshtas bool isAckorReply = (p->which_payload_variant == meshtastic_MeshPacket_decoded_tag) && (p->decoded.request_id != 0); if (isAckorReply && p->to != getNodeNum() && p->to != NODENUM_BROADCAST) { // do not flood direct message that is ACKed or replied to - LOG_DEBUG("Receiving an ACK or reply not for me, but don't need to rebroadcast this direct message anymore.\n"); + LOG_DEBUG("Rxd an ACK/reply not for me, cancel rebroadcast.\n"); Router::cancelSending(p->to, p->decoded.request_id); // cancel rebroadcast for this DM } if ((p->to != getNodeNum()) && (p->hop_limit > 0) && (getFrom(p) != getNodeNum())) { @@ -55,7 +55,7 @@ void FloodingRouter::sniffReceived(const meshtastic_MeshPacket *p, const meshtas } #endif - LOG_INFO("Rebroadcasting received floodmsg to neighbors\n"); + LOG_INFO("Rebroadcasting received floodmsg\n"); // Note: we are careful to resend using the original senders node id // We are careful not to call our hooked version of send() - because we don't want to check this again Router::send(tosend); @@ -63,7 +63,7 @@ void FloodingRouter::sniffReceived(const meshtastic_MeshPacket *p, const meshtas LOG_DEBUG("Not rebroadcasting. Role = Role_ClientMute\n"); } } else { - LOG_DEBUG("Ignoring a simple (0 id) broadcast\n"); + LOG_DEBUG("Ignoring 0 id broadcast\n"); } } // handle the packet as normal diff --git a/src/mesh/MeshService.cpp b/src/mesh/MeshService.cpp index ac97d51a71..a8a2073528 100644 --- a/src/mesh/MeshService.cpp +++ b/src/mesh/MeshService.cpp @@ -80,12 +80,11 @@ int MeshService::handleFromRadio(const meshtastic_MeshPacket *mp) nodeDB->updateFrom(*mp); // update our DB state based off sniffing every RX packet from the radio if (mp->which_payload_variant == meshtastic_MeshPacket_decoded_tag && mp->decoded.portnum == meshtastic_PortNum_TELEMETRY_APP && mp->decoded.request_id > 0) { - LOG_DEBUG( - "Received telemetry response. Skip sending our NodeInfo because this potentially a Repeater which will ignore our " - "request for its NodeInfo.\n"); + LOG_DEBUG("Received telemetry response. Skip sending our NodeInfo.\n"); // because this potentially a Repeater which will + // ignore our request for its NodeInfo } else if (mp->which_payload_variant == meshtastic_MeshPacket_decoded_tag && !nodeDB->getMeshNode(mp->from)->has_user && nodeInfoModule) { - LOG_INFO("Heard a node on channel %d we don't know, sending NodeInfo and asking for a response.\n", mp->channel); + LOG_INFO("Heard new node on channel %d, sending NodeInfo and asking for a response.\n", mp->channel); if (airTime->isTxAllowedChannelUtil(true)) { nodeInfoModule->sendOurNodeInfo(mp->from, true, mp->channel); } else { @@ -223,7 +222,7 @@ ErrorCode MeshService::sendQueueStatusToPhone(const meshtastic_QueueStatus &qs, copied->mesh_packet_id = mesh_packet_id; if (toPhoneQueueStatusQueue.numFree() == 0) { - LOG_DEBUG("NOTE: tophone queue status queue is full, discarding oldest\n"); + LOG_INFO("tophone queue status queue is full, discarding oldest\n"); meshtastic_QueueStatus *d = toPhoneQueueStatusQueue.dequeuePtr(0); if (d) releaseQueueStatusToPool(d); @@ -317,7 +316,7 @@ void MeshService::sendToPhone(meshtastic_MeshPacket *p) void MeshService::sendMqttMessageToClientProxy(meshtastic_MqttClientProxyMessage *m) { - LOG_DEBUG("Sending mqtt message on topic '%s' to client for proxying to server\n", m->topic); + LOG_DEBUG("Sending mqtt message on topic '%s' to client for proxy\n", m->topic); if (toPhoneMqttProxyQueue.numFree() == 0) { LOG_WARN("MqttClientProxyMessagePool queue is full, discarding oldest\n"); meshtastic_MqttClientProxyMessage *d = toPhoneMqttProxyQueue.dequeuePtr(0); @@ -407,4 +406,4 @@ int MeshService::onGPSChanged(const meshtastic::GPSStatus *newStatus) bool MeshService::isToPhoneQueueEmpty() { return toPhoneQueue.isEmpty(); -} +} \ No newline at end of file diff --git a/src/mesh/NodeDB.cpp b/src/mesh/NodeDB.cpp index 36b9f3ff48..b78827e65a 100644 --- a/src/mesh/NodeDB.cpp +++ b/src/mesh/NodeDB.cpp @@ -1079,7 +1079,7 @@ bool NodeDB::updateUser(uint32_t nodeId, meshtastic_User &p, uint8_t channelInde // We just changed something about the user, store our DB Throttle::execute( &lastNodeDbSave, ONE_MINUTE_MS, []() { nodeDB->saveToDisk(SEGMENT_DEVICESTATE); }, - []() { LOG_DEBUG("Deferring NodeDB saveToDisk for now, since we saved less than a minute ago\n"); }); + []() { LOG_DEBUG("Deferring NodeDB saveToDisk for now\n"); }); // since we saved less than a minute ago } return changed; diff --git a/src/mesh/RF95Interface.cpp b/src/mesh/RF95Interface.cpp index 3cb6bfddaf..581fd90342 100644 --- a/src/mesh/RF95Interface.cpp +++ b/src/mesh/RF95Interface.cpp @@ -220,17 +220,17 @@ bool RF95Interface::reconfigure() err = lora->setSyncWord(syncWord); if (err != RADIOLIB_ERR_NONE) - LOG_ERROR("Radiolib error %d when attempting RF95 setSyncWord!\n", err); + LOG_ERROR("RF95 setSyncWord %s%d\n", radioLibErr, err); assert(err == RADIOLIB_ERR_NONE); err = lora->setCurrentLimit(currentLimit); if (err != RADIOLIB_ERR_NONE) - LOG_ERROR("Radiolib error %d when attempting RF95 setCurrentLimit!\n", err); + LOG_ERROR("RF95 setCurrentLimit %s%d\n", radioLibErr, err); assert(err == RADIOLIB_ERR_NONE); err = lora->setPreambleLength(preambleLength); if (err != RADIOLIB_ERR_NONE) - LOG_ERROR("Radiolib error %d when attempting RF95 setPreambleLength!\n", err); + LOG_ERROR(" RF95 setPreambleLength %s%d\n", radioLibErr, err); assert(err == RADIOLIB_ERR_NONE); err = lora->setFrequency(getFreq()); @@ -266,7 +266,7 @@ void RF95Interface::setStandby() { int err = lora->standby(); if (err != RADIOLIB_ERR_NONE) - LOG_ERROR("Radiolib error %d when attempting RF95 standby!\n", err); + LOG_ERROR("RF95 standby %s%d\n", radioLibErr, err); assert(err == RADIOLIB_ERR_NONE); isReceiving = false; // If we were receiving, not any more @@ -290,7 +290,7 @@ void RF95Interface::startReceive() setStandby(); int err = lora->startReceive(); if (err != RADIOLIB_ERR_NONE) - LOG_ERROR("Radiolib error %d when attempting RF95 startReceive!\n", err); + LOG_ERROR("RF95 startReceive %s%d\n", radioLibErr, err); assert(err == RADIOLIB_ERR_NONE); isReceiving = true; @@ -312,7 +312,7 @@ bool RF95Interface::isChannelActive() return true; } if (result != RADIOLIB_CHANNEL_FREE) - LOG_ERROR("Radiolib error %d when attempting RF95 isChannelActive!\n", result); + LOG_ERROR("RF95 isChannelActive %s%d\n", radioLibErr, result); assert(result != RADIOLIB_ERR_WRONG_MODEM); // LOG_DEBUG("Channel is free!\n"); diff --git a/src/mesh/RadioInterface.cpp b/src/mesh/RadioInterface.cpp index 683ae7e013..b915f94bda 100644 --- a/src/mesh/RadioInterface.cpp +++ b/src/mesh/RadioInterface.cpp @@ -202,8 +202,6 @@ uint32_t RadioInterface::getPacketTime(uint32_t pl) uint32_t msecs = tPacket * 1000; - LOG_DEBUG("(bw=%d, sf=%d, cr=4/%d) packet symLen=%d ms, payloadSize=%u, time %d ms\n", (int)bw, sf, cr, (int)(tSym * 1000), - pl, msecs); return msecs; } @@ -550,11 +548,11 @@ void RadioInterface::applyModemConfig() LOG_INFO("Radio freq=%.3f, config.lora.frequency_offset=%.3f\n", freq, loraConfig.frequency_offset); LOG_INFO("Set radio: region=%s, name=%s, config=%u, ch=%d, power=%d\n", myRegion->name, channelName, loraConfig.modem_preset, channel_num, power); - LOG_INFO("Radio myRegion->freqStart -> myRegion->freqEnd: %f -> %f (%f MHz)\n", myRegion->freqStart, myRegion->freqEnd, + LOG_INFO("myRegion->freqStart -> myRegion->freqEnd: %f -> %f (%f MHz)\n", myRegion->freqStart, myRegion->freqEnd, myRegion->freqEnd - myRegion->freqStart); - LOG_INFO("Radio myRegion->numChannels: %d x %.3fkHz\n", numChannels, bw); - LOG_INFO("Radio channel_num: %d\n", channel_num + 1); - LOG_INFO("Radio frequency: %f\n", getFreq()); + LOG_INFO("numChannels: %d x %.3fkHz\n", numChannels, bw); + LOG_INFO("channel_num: %d\n", channel_num + 1); + LOG_INFO("frequency: %f\n", getFreq()); LOG_INFO("Slot time: %u msec\n", slotTimeMsec); } diff --git a/src/mesh/RadioLibInterface.cpp b/src/mesh/RadioLibInterface.cpp index 664709ed1e..807c8aa021 100644 --- a/src/mesh/RadioLibInterface.cpp +++ b/src/mesh/RadioLibInterface.cpp @@ -466,7 +466,7 @@ void RadioLibInterface::startSend(meshtastic_MeshPacket *txp) { printPacket("Starting low level send", txp); if (disabled || !config.lora.tx_enabled) { - LOG_WARN("startSend is dropping tx packet because we are disabled\n"); + LOG_WARN("Drop Tx packet because LoRa Tx disabled\n"); packetPool.release(txp); } else { configHardwareForSend(); // must be after setStandby diff --git a/src/mesh/RadioLibInterface.h b/src/mesh/RadioLibInterface.h index 13bef851a1..090c030467 100644 --- a/src/mesh/RadioLibInterface.h +++ b/src/mesh/RadioLibInterface.h @@ -196,4 +196,6 @@ class RadioLibInterface : public RadioInterface, protected concurrency::Notified * Subclasses must override, implement and then call into this base class implementation */ virtual void setStandby(); + + const char *radioLibErr = "RadioLib err=\n"; }; \ No newline at end of file diff --git a/src/mesh/ReliableRouter.cpp b/src/mesh/ReliableRouter.cpp index 1f2c014733..9482f41856 100644 --- a/src/mesh/ReliableRouter.cpp +++ b/src/mesh/ReliableRouter.cpp @@ -107,12 +107,12 @@ void ReliableRouter::sniffReceived(const meshtastic_MeshPacket *p, const meshtas if (p->to == ourNode) { // ignore ack/nak/want_ack packets that are not address to us (we only handle 0 hop reliability) if (p->want_ack) { if (MeshModule::currentReply) { - LOG_DEBUG("Some other module has replied to this message, no need for a 2nd ack\n"); + LOG_DEBUG("Another module replied to this message, no need for 2nd ack\n"); } else if (p->which_payload_variant == meshtastic_MeshPacket_decoded_tag) { sendAckNak(meshtastic_Routing_Error_NONE, getFrom(p), p->id, p->channel, p->hop_start, p->hop_limit); } else if (p->which_payload_variant == meshtastic_MeshPacket_encrypted_tag && p->channel == 0 && (nodeDB->getMeshNode(p->from) == nullptr || nodeDB->getMeshNode(p->from)->user.public_key.size == 0)) { - LOG_INFO("This looks like it might be a PKI packet from an unknown node, so send PKI_UNKNOWN_PUBKEY\n"); + LOG_INFO("PKI packet from unknown node, send PKI_UNKNOWN_PUBKEY\n"); sendAckNak(meshtastic_Routing_Error_PKI_UNKNOWN_PUBKEY, getFrom(p), p->id, channels.getPrimaryIndex(), p->hop_start, p->hop_limit); } else { @@ -124,7 +124,7 @@ void ReliableRouter::sniffReceived(const meshtastic_MeshPacket *p, const meshtas if (p->which_payload_variant == meshtastic_MeshPacket_decoded_tag && c && c->error_reason == meshtastic_Routing_Error_PKI_UNKNOWN_PUBKEY) { if (owner.public_key.size == 32) { - LOG_INFO("This seems like a remote PKI decrypt failure, so send a NodeInfo"); + LOG_INFO("PKI decrypt failure, send a NodeInfo"); nodeInfoModule->sendOurNodeInfo(p->from, false, p->channel, true); } } @@ -136,11 +136,10 @@ void ReliableRouter::sniffReceived(const meshtastic_MeshPacket *p, const meshtas // We intentionally don't check wasSeenRecently, because it is harmless to delete non existent retransmission records if (ackId || nakId) { + LOG_DEBUG("Received a %s for 0x%x, stopping retransmissions\n", ackId ? "ACK" : "NAK", ackId); if (ackId) { - LOG_DEBUG("Received an ack for 0x%x, stopping retransmissions\n", ackId); stopRetransmission(p->to, ackId); } else { - LOG_DEBUG("Received a nak for 0x%x, stopping retransmissions\n", nakId); stopRetransmission(p->to, nakId); } } diff --git a/src/mesh/Router.cpp b/src/mesh/Router.cpp index bb04b66ac1..610d5303e1 100644 --- a/src/mesh/Router.cpp +++ b/src/mesh/Router.cpp @@ -503,8 +503,8 @@ meshtastic_Routing_Error perhapsEncode(meshtastic_MeshPacket *p) return meshtastic_Routing_Error_TOO_LARGE; if (p->pki_encrypted && !memfll(p->public_key.bytes, 0, 32) && memcmp(p->public_key.bytes, node->user.public_key.bytes, 32) != 0) { - LOG_WARN("Client public key for client differs from requested! Requested 0x%02x, but stored key begins 0x%02x\n", - *p->public_key.bytes, *node->user.public_key.bytes); + LOG_WARN("Client public key differs from requested: 0x%02x, stored key begins 0x%02x\n", *p->public_key.bytes, + *node->user.public_key.bytes); return meshtastic_Routing_Error_PKI_FAILED; } crypto->encryptCurve25519(p->to, getFrom(p), p->id, numbytes, bytes, ScratchEncrypted); diff --git a/src/mesh/SX126xInterface.cpp b/src/mesh/SX126xInterface.cpp index a23c1e4578..924cdfa9f4 100644 --- a/src/mesh/SX126xInterface.cpp +++ b/src/mesh/SX126xInterface.cpp @@ -203,17 +203,17 @@ template bool SX126xInterface::reconfigure() err = lora.setSyncWord(syncWord); if (err != RADIOLIB_ERR_NONE) - LOG_ERROR("Radiolib error %d when attempting SX126X setSyncWord!\n", err); + LOG_ERROR("SX126X setSyncWord %s%d\n", radioLibErr, err); assert(err == RADIOLIB_ERR_NONE); err = lora.setCurrentLimit(currentLimit); if (err != RADIOLIB_ERR_NONE) - LOG_ERROR("Radiolib error %d when attempting SX126X setCurrentLimit!\n", err); + LOG_ERROR("SX126X setCurrentLimit %s%d\n", radioLibErr, err); assert(err == RADIOLIB_ERR_NONE); err = lora.setPreambleLength(preambleLength); if (err != RADIOLIB_ERR_NONE) - LOG_ERROR("Radiolib error %d when attempting SX126X setPreambleLength!\n", err); + LOG_ERROR("SX126X setPreambleLength %s%d\n", radioLibErr, err); assert(err == RADIOLIB_ERR_NONE); err = lora.setFrequency(getFreq()); @@ -225,7 +225,7 @@ template bool SX126xInterface::reconfigure() err = lora.setOutputPower(power); if (err != RADIOLIB_ERR_NONE) - LOG_ERROR("Radiolib error %d when attempting SX126X setOutputPower!\n", err); + LOG_ERROR("SX126X setOutputPower %s%d\n", radioLibErr, err); assert(err == RADIOLIB_ERR_NONE); startReceive(); // restart receiving @@ -245,7 +245,7 @@ template void SX126xInterface::setStandby() int err = lora.standby(); if (err != RADIOLIB_ERR_NONE) - LOG_DEBUG("SX126x standby failed with error %d\n", err); + LOG_DEBUG("SX126x standby %s%d\n", radioLibErr, err); assert(err == RADIOLIB_ERR_NONE); isReceiving = false; // If we were receiving, not any more @@ -287,7 +287,7 @@ template void SX126xInterface::startReceive() // Furthermore, we need the PREAMBLE_DETECTED and HEADER_VALID IRQ flag to detect whether we are actively receiving int err = lora.startReceiveDutyCycleAuto(preambleLength, 8, RADIOLIB_IRQ_RX_DEFAULT_FLAGS | RADIOLIB_IRQ_PREAMBLE_DETECTED); if (err != RADIOLIB_ERR_NONE) - LOG_ERROR("Radiolib error %d when attempting SX126X startReceiveDutyCycleAuto!\n", err); + LOG_ERROR("SX126X startReceiveDutyCycleAuto %s%d\n", radioLibErr, err); assert(err == RADIOLIB_ERR_NONE); RadioLibInterface::startReceive(); @@ -308,7 +308,7 @@ template bool SX126xInterface::isChannelActive() if (result == RADIOLIB_LORA_DETECTED) return true; if (result != RADIOLIB_CHANNEL_FREE) - LOG_ERROR("Radiolib error %d when attempting SX126X scanChannel!\n", result); + LOG_ERROR("SX126X scanChannel %s%d\n", radioLibErr, result); assert(result != RADIOLIB_ERR_WRONG_MODEM); return false; @@ -326,8 +326,8 @@ template bool SX126xInterface::sleep() { // Not keeping config is busted - next time nrf52 board boots lora sending fails tcxo related? - see datasheet // \todo Display actual typename of the adapter, not just `SX126x` - LOG_DEBUG("SX126x entering sleep mode (FIXME, don't keep config)\n"); - setStandby(); // Stop any pending operations + LOG_DEBUG("SX126x entering sleep mode\n"); // (FIXME, don't keep config) + setStandby(); // Stop any pending operations // turn off TCXO if it was powered // FIXME - this isn't correct diff --git a/src/mesh/SX128xInterface.cpp b/src/mesh/SX128xInterface.cpp index 2a1bb4e410..d379f26e6a 100644 --- a/src/mesh/SX128xInterface.cpp +++ b/src/mesh/SX128xInterface.cpp @@ -129,12 +129,12 @@ template bool SX128xInterface::reconfigure() err = lora.setSyncWord(syncWord); if (err != RADIOLIB_ERR_NONE) - LOG_ERROR("Radiolib error %d when attempting SX128X setSyncWord!\n", err); + LOG_ERROR("SX128X setSyncWord %s%d\n", radioLibErr, err); assert(err == RADIOLIB_ERR_NONE); err = lora.setPreambleLength(preambleLength); if (err != RADIOLIB_ERR_NONE) - LOG_ERROR("Radiolib error %d when attempting SX128X setPreambleLength!\n", err); + LOG_ERROR("SX128X setPreambleLength %s%d\n", radioLibErr, err); assert(err == RADIOLIB_ERR_NONE); err = lora.setFrequency(getFreq()); @@ -146,7 +146,7 @@ template bool SX128xInterface::reconfigure() err = lora.setOutputPower(power); if (err != RADIOLIB_ERR_NONE) - LOG_ERROR("Radiolib error %d when attempting SX128X setOutputPower!\n", err); + LOG_ERROR("SX128X setOutputPower %s%d\n", radioLibErr, err); assert(err == RADIOLIB_ERR_NONE); startReceive(); // restart receiving @@ -171,7 +171,7 @@ template void SX128xInterface::setStandby() int err = lora.standby(); if (err != RADIOLIB_ERR_NONE) - LOG_ERROR("SX128x standby failed with error %d\n", err); + LOG_ERROR("SX128x standby %s%d\n", radioLibErr, err); assert(err == RADIOLIB_ERR_NONE); #if ARCH_PORTDUINO if (settingsMap[rxen] != RADIOLIB_NC) { @@ -261,7 +261,7 @@ template void SX128xInterface::startReceive() int err = lora.startReceive(RADIOLIB_SX128X_RX_TIMEOUT_INF, RADIOLIB_IRQ_RX_DEFAULT_FLAGS | RADIOLIB_IRQ_PREAMBLE_DETECTED); if (err != RADIOLIB_ERR_NONE) - LOG_ERROR("Radiolib error %d when attempting SX128X startReceive!\n", err); + LOG_ERROR("SX128X startReceive %s%d\n", radioLibErr, err); assert(err == RADIOLIB_ERR_NONE); RadioLibInterface::startReceive(); @@ -282,7 +282,7 @@ template bool SX128xInterface::isChannelActive() if (result == RADIOLIB_LORA_DETECTED) return true; if (result != RADIOLIB_CHANNEL_FREE) - LOG_ERROR("Radiolib error %d when attempting SX128X scanChannel!\n", result); + LOG_ERROR("SX128X scanChannel %s%d\n", radioLibErr, result); assert(result != RADIOLIB_ERR_WRONG_MODEM); return false; @@ -298,8 +298,8 @@ template bool SX128xInterface::sleep() { // Not keeping config is busted - next time nrf52 board boots lora sending fails tcxo related? - see datasheet // \todo Display actual typename of the adapter, not just `SX128x` - LOG_DEBUG("SX128x entering sleep mode (FIXME, don't keep config)\n"); - setStandby(); // Stop any pending operations + LOG_DEBUG("SX128x entering sleep mode\n"); // (FIXME, don't keep config) + setStandby(); // Stop any pending operations // turn off TCXO if it was powered // FIXME - this isn't correct diff --git a/src/mesh/http/ContentHandler.cpp b/src/mesh/http/ContentHandler.cpp index 772b3e821b..c5ea86429e 100644 --- a/src/mesh/http/ContentHandler.cpp +++ b/src/mesh/http/ContentHandler.cpp @@ -776,7 +776,7 @@ void handleRestart(HTTPRequest *req, HTTPResponse *res) res->println("

Meshtastic

\n"); res->println("Restarting"); - LOG_DEBUG("***** Restarted on HTTP(s) Request *****\n"); + LOG_DEBUG("Restarted on HTTP(s) Request\n"); webServerThread->requestRestart = (millis() / 1000) + 5; } diff --git a/src/modules/StoreForwardModule.cpp b/src/modules/StoreForwardModule.cpp index 5f30803a4b..58be8c01ed 100644 --- a/src/modules/StoreForwardModule.cpp +++ b/src/modules/StoreForwardModule.cpp @@ -46,7 +46,7 @@ int32_t StoreForwardModule::runOnce() } else if (this->heartbeat && (!Throttle::isWithinTimespanMs(lastHeartbeat, heartbeatInterval * 1000)) && airTime->isTxAllowedChannelUtil(true)) { lastHeartbeat = millis(); - LOG_INFO("*** Sending heartbeat\n"); + LOG_INFO("Sending heartbeat\n"); meshtastic_StoreAndForward sf = meshtastic_StoreAndForward_init_zero; sf.rr = meshtastic_StoreAndForward_RequestResponse_ROUTER_HEARTBEAT; sf.which_variant = meshtastic_StoreAndForward_heartbeat_tag; @@ -70,8 +70,8 @@ void StoreForwardModule::populatePSRAM() https://learn.upesy.com/en/programmation/psram.html#psram-tab */ - LOG_DEBUG("*** Before PSRAM initialization: heap %d/%d PSRAM %d/%d\n", memGet.getFreeHeap(), memGet.getHeapSize(), - memGet.getFreePsram(), memGet.getPsramSize()); + LOG_DEBUG("Before PSRAM init: heap %d/%d PSRAM %d/%d\n", memGet.getFreeHeap(), memGet.getHeapSize(), memGet.getFreePsram(), + memGet.getPsramSize()); /* Use a maximum of 2/3 the available PSRAM unless otherwise specified. Note: This needs to be done after every thing that would use PSRAM @@ -86,9 +86,9 @@ void StoreForwardModule::populatePSRAM() #endif - LOG_DEBUG("*** After PSRAM initialization: heap %d/%d PSRAM %d/%d\n", memGet.getFreeHeap(), memGet.getHeapSize(), - memGet.getFreePsram(), memGet.getPsramSize()); - LOG_DEBUG("*** numberOfPackets for packetHistory - %u\n", numberOfPackets); + LOG_DEBUG("After PSRAM init: heap %d/%d PSRAM %d/%d\n", memGet.getFreeHeap(), memGet.getHeapSize(), memGet.getFreePsram(), + memGet.getPsramSize()); + LOG_DEBUG("numberOfPackets for packetHistory - %u\n", numberOfPackets); } /** @@ -105,11 +105,11 @@ void StoreForwardModule::historySend(uint32_t secAgo, uint32_t to) queueSize = this->historyReturnMax; if (queueSize) { - LOG_INFO("*** S&F - Sending %u message(s)\n", queueSize); + LOG_INFO("S&F - Sending %u message(s)\n", queueSize); this->busy = true; // runOnce() will pickup the next steps once busy = true. this->busyTo = to; } else { - LOG_INFO("*** S&F - No history to send\n"); + LOG_INFO("S&F - No history\n"); } meshtastic_StoreAndForward sf = meshtastic_StoreAndForward_init_zero; sf.rr = meshtastic_StoreAndForward_RequestResponse_ROUTER_HISTORY; @@ -187,7 +187,7 @@ void StoreForwardModule::historyAdd(const meshtastic_MeshPacket &mp) const auto &p = mp.decoded; if (this->packetHistoryTotalCount == this->records) { - LOG_WARN("*** S&F - PSRAM Full. Starting overwrite now.\n"); + LOG_WARN("S&F - PSRAM Full. Starting overwrite.\n"); this->packetHistoryTotalCount = 0; for (auto &i : lastRequest) { i.second = 0; // Clear the last request index for each client device @@ -215,7 +215,7 @@ bool StoreForwardModule::sendPayload(NodeNum dest, uint32_t last_time) { meshtastic_MeshPacket *p = preparePayload(dest, last_time); if (p) { - LOG_INFO("*** Sending S&F Payload\n"); + LOG_INFO("Sending S&F Payload\n"); service->sendToMesh(p); this->requestCount++; return true; @@ -331,9 +331,9 @@ void StoreForwardModule::sendErrorTextMessage(NodeNum dest, bool want_response) pr->decoded.portnum = meshtastic_PortNum_TEXT_MESSAGE_APP; const char *str; if (this->busy) { - str = "** S&F - Busy. Try again shortly."; + str = "S&F - Busy. Try again shortly."; } else { - str = "** S&F - Not available on this channel."; + str = "S&F - Not available on this channel."; } LOG_WARN("%s\n", str); memcpy(pr->decoded.payload.bytes, str, strlen(str)); @@ -365,7 +365,7 @@ void StoreForwardModule::statsSend(uint32_t to) sf.variant.stats.return_max = this->historyReturnMax; sf.variant.stats.return_window = this->historyReturnWindow; - LOG_DEBUG("*** Sending S&F Stats\n"); + LOG_DEBUG("Sending S&F Stats\n"); storeForwardModule->sendMessage(to, sf); } @@ -384,7 +384,7 @@ ProcessMessage StoreForwardModule::handleReceived(const meshtastic_MeshPacket &m auto &p = mp.decoded; if (mp.to == nodeDB->getNodeNum() && (p.payload.bytes[0] == 'S') && (p.payload.bytes[1] == 'F') && (p.payload.bytes[2] == 0x00)) { - LOG_DEBUG("*** Legacy Request to send\n"); + LOG_DEBUG("Legacy Request to send\n"); // Send the last 60 minutes of messages. if (this->busy || channels.isDefaultChannel(mp.channel)) { @@ -394,7 +394,7 @@ ProcessMessage StoreForwardModule::handleReceived(const meshtastic_MeshPacket &m } } else { storeForwardModule->historyAdd(mp); - LOG_INFO("*** S&F stored. Message history contains %u records now.\n", this->packetHistoryTotalCount); + LOG_INFO("S&F stored. Message history contains %u records now.\n", this->packetHistoryTotalCount); } } else if (getFrom(&mp) != nodeDB->getNodeNum() && mp.decoded.portnum == meshtastic_PortNum_STORE_FORWARD_APP) { auto &p = mp.decoded; @@ -440,7 +440,7 @@ bool StoreForwardModule::handleReceivedProtobuf(const meshtastic_MeshPacket &mp, if (is_server) { // stop sending stuff, the client wants to abort or has another error if ((this->busy) && (this->busyTo == getFrom(&mp))) { - LOG_ERROR("*** Client in ERROR or ABORT requested\n"); + LOG_ERROR("Client in ERROR or ABORT requested\n"); this->requestCount = 0; this->busy = false; } @@ -450,7 +450,7 @@ bool StoreForwardModule::handleReceivedProtobuf(const meshtastic_MeshPacket &mp, case meshtastic_StoreAndForward_RequestResponse_CLIENT_HISTORY: if (is_server) { requests_history++; - LOG_INFO("*** Client Request to send HISTORY\n"); + LOG_INFO("Client Request to send HISTORY\n"); // Send the last 60 minutes of messages. if (this->busy || channels.isDefaultChannel(mp.channel)) { sendErrorTextMessage(getFrom(&mp), mp.decoded.want_response); @@ -467,7 +467,6 @@ bool StoreForwardModule::handleReceivedProtobuf(const meshtastic_MeshPacket &mp, case meshtastic_StoreAndForward_RequestResponse_CLIENT_PING: if (is_server) { - LOG_INFO("*** StoreAndForward_RequestResponse_CLIENT_PING\n"); // respond with a ROUTER PONG storeForwardModule->sendMessage(getFrom(&mp), meshtastic_StoreAndForward_RequestResponse_ROUTER_PONG); } @@ -475,17 +474,16 @@ bool StoreForwardModule::handleReceivedProtobuf(const meshtastic_MeshPacket &mp, case meshtastic_StoreAndForward_RequestResponse_CLIENT_PONG: if (is_server) { - LOG_INFO("*** StoreAndForward_RequestResponse_CLIENT_PONG\n"); // NodeDB is already updated } break; case meshtastic_StoreAndForward_RequestResponse_CLIENT_STATS: if (is_server) { - LOG_INFO("*** Client Request to send STATS\n"); + LOG_INFO("Client Request to send STATS\n"); if (this->busy) { storeForwardModule->sendMessage(getFrom(&mp), meshtastic_StoreAndForward_RequestResponse_ROUTER_BUSY); - LOG_INFO("*** S&F - Busy. Try again shortly.\n"); + LOG_INFO("S&F - Busy. Try again shortly.\n"); } else { storeForwardModule->statsSend(getFrom(&mp)); } @@ -495,7 +493,7 @@ bool StoreForwardModule::handleReceivedProtobuf(const meshtastic_MeshPacket &mp, case meshtastic_StoreAndForward_RequestResponse_ROUTER_ERROR: case meshtastic_StoreAndForward_RequestResponse_ROUTER_BUSY: if (is_client) { - LOG_DEBUG("*** StoreAndForward_RequestResponse_ROUTER_BUSY\n"); + LOG_DEBUG("StoreAndForward_RequestResponse_ROUTER_BUSY\n"); // retry in messages_saved * packetTimeMax ms retry_delay = millis() + getNumAvailablePackets(this->busyTo, this->last_time) * packetTimeMax * (meshtastic_StoreAndForward_RequestResponse_ROUTER_ERROR ? 2 : 1); @@ -511,13 +509,12 @@ bool StoreForwardModule::handleReceivedProtobuf(const meshtastic_MeshPacket &mp, heartbeatInterval = p->variant.heartbeat.period; } lastHeartbeat = millis(); - LOG_INFO("*** StoreAndForward Heartbeat received\n"); + LOG_INFO("StoreAndForward Heartbeat received\n"); } break; case meshtastic_StoreAndForward_RequestResponse_ROUTER_PING: if (is_client) { - LOG_DEBUG("*** StoreAndForward_RequestResponse_ROUTER_PING\n"); // respond with a CLIENT PONG storeForwardModule->sendMessage(getFrom(&mp), meshtastic_StoreAndForward_RequestResponse_CLIENT_PONG); } @@ -525,7 +522,7 @@ bool StoreForwardModule::handleReceivedProtobuf(const meshtastic_MeshPacket &mp, case meshtastic_StoreAndForward_RequestResponse_ROUTER_STATS: if (is_client) { - LOG_DEBUG("*** Router Response STATS\n"); + LOG_DEBUG("Router Response STATS\n"); // These fields only have informational purpose on a client. Fill them to consume later. if (p->which_variant == meshtastic_StoreAndForward_stats_tag) { this->records = p->variant.stats.messages_max; @@ -543,7 +540,7 @@ bool StoreForwardModule::handleReceivedProtobuf(const meshtastic_MeshPacket &mp, // These fields only have informational purpose on a client. Fill them to consume later. if (p->which_variant == meshtastic_StoreAndForward_history_tag) { this->historyReturnWindow = p->variant.history.window / 60000; - LOG_INFO("*** Router Response HISTORY - Sending %d messages from last %d minutes\n", + LOG_INFO("Router Response HISTORY - Sending %d messages from last %d minutes\n", p->variant.history.history_messages, this->historyReturnWindow); } } @@ -577,7 +574,7 @@ StoreForwardModule::StoreForwardModule() // Router if ((config.device.role == meshtastic_Config_DeviceConfig_Role_ROUTER || moduleConfig.store_forward.is_server)) { - LOG_INFO("*** Initializing Store & Forward Module in Server mode\n"); + LOG_INFO("Initializing Store & Forward Module in Server mode\n"); if (memGet.getPsramSize() > 0) { if (memGet.getFreePsram() >= 1024 * 1024) { @@ -605,18 +602,17 @@ StoreForwardModule::StoreForwardModule() this->populatePSRAM(); is_server = true; } else { - LOG_INFO("*** Device has less than 1M of PSRAM free.\n"); - LOG_INFO("*** Store & Forward Module - disabling server.\n"); + LOG_INFO(".\n"); + LOG_INFO("S&F: not enough PSRAM free, disabling.\n"); } } else { - LOG_INFO("*** Device doesn't have PSRAM.\n"); - LOG_INFO("*** Store & Forward Module - disabling server.\n"); + LOG_INFO("S&F: device doesn't have PSRAM, disabling.\n"); } // Client } else { is_client = true; - LOG_INFO("*** Initializing Store & Forward Module in Client mode\n"); + LOG_INFO("Initializing Store & Forward Module in Client mode\n"); } } else { disable(); diff --git a/src/modules/Telemetry/PowerTelemetry.cpp b/src/modules/Telemetry/PowerTelemetry.cpp index d318920428..038cbfadc2 100644 --- a/src/modules/Telemetry/PowerTelemetry.cpp +++ b/src/modules/Telemetry/PowerTelemetry.cpp @@ -255,7 +255,7 @@ bool PowerTelemetryModule::sendTelemetry(NodeNum dest, bool phoneOnly) service->sendToMesh(p, RX_SRC_LOCAL, true); if (config.device.role == meshtastic_Config_DeviceConfig_Role_SENSOR && config.power.is_power_saving) { - LOG_DEBUG("Starting next execution in 5 seconds and then going to sleep.\n"); + LOG_DEBUG("Starting next execution in 5s then going to sleep.\n"); sleepOnNextExecution = true; setIntervalFromNow(5000); } diff --git a/src/modules/Telemetry/Sensor/MAX17048Sensor.cpp b/src/modules/Telemetry/Sensor/MAX17048Sensor.cpp index a3890df439..96dd5ae80e 100644 --- a/src/modules/Telemetry/Sensor/MAX17048Sensor.cpp +++ b/src/modules/Telemetry/Sensor/MAX17048Sensor.cpp @@ -19,7 +19,7 @@ MAX17048Singleton *MAX17048Singleton::pinstance{nullptr}; bool MAX17048Singleton::runOnce(TwoWire *theWire) { initialized = begin(theWire); - LOG_DEBUG("MAX17048Sensor::runOnce %s\n", initialized ? "began ok" : "begin failed"); + LOG_DEBUG("%s::runOnce %s\n", sensorStr, initialized ? "began ok" : "begin failed"); return initialized; } @@ -27,7 +27,7 @@ bool MAX17048Singleton::isBatteryCharging() { float volts = cellVoltage(); if (isnan(volts)) { - LOG_DEBUG("MAX17048Sensor::isBatteryCharging is not connected\n"); + LOG_DEBUG("%s::isBatteryCharging is not connected\n", sensorStr); return 0; } @@ -53,7 +53,7 @@ bool MAX17048Singleton::isBatteryCharging() chargeState = MAX17048ChargeState::IDLE; } - LOG_DEBUG("MAX17048Sensor::isBatteryCharging %s volts: %.3f soc: %.3f rate: %.3f\n", chargeLabels[chargeState], volts, + LOG_DEBUG("%s::isBatteryCharging %s volts: %.3f soc: %.3f rate: %.3f\n", sensorStr, chargeLabels[chargeState], volts, sample.cellPercent, sample.chargeRate); return chargeState == MAX17048ChargeState::IMPORT; } @@ -62,17 +62,17 @@ uint16_t MAX17048Singleton::getBusVoltageMv() { float volts = cellVoltage(); if (isnan(volts)) { - LOG_DEBUG("MAX17048Sensor::getBusVoltageMv is not connected\n"); + LOG_DEBUG("%s::getBusVoltageMv is not connected\n", sensorStr); return 0; } - LOG_DEBUG("MAX17048Sensor::getBusVoltageMv %.3fmV\n", volts); + LOG_DEBUG("%s::getBusVoltageMv %.3fmV\n", sensorStr, volts); return (uint16_t)(volts * 1000.0f); } uint8_t MAX17048Singleton::getBusBatteryPercent() { float soc = cellPercent(); - LOG_DEBUG("MAX17048Sensor::getBusBatteryPercent %.1f%%\n", soc); + LOG_DEBUG("%s::getBusBatteryPercent %.1f%%\n", sensorStr, soc); return clamp(static_cast(round(soc)), static_cast(0), static_cast(100)); } @@ -82,7 +82,7 @@ uint16_t MAX17048Singleton::getTimeToGoSecs() float soc = cellPercent(); // state of charge in percent 0 to 100 soc = clamp(soc, 0.0f, 100.0f); // clamp soc between 0 and 100% float ttg = ((100.0f - soc) / rate) * 3600.0f; // calculate seconds to charge/discharge - LOG_DEBUG("MAX17048Sensor::getTimeToGoSecs %.0f seconds\n", ttg); + LOG_DEBUG("%s::getTimeToGoSecs %.0f seconds\n", sensorStr, ttg); return (uint16_t)ttg; } @@ -90,7 +90,7 @@ bool MAX17048Singleton::isBatteryConnected() { float volts = cellVoltage(); if (isnan(volts)) { - LOG_DEBUG("MAX17048Sensor::isBatteryConnected is not connected\n"); + LOG_DEBUG("%s::isBatteryConnected is not connected\n", sensorStr); return false; } @@ -103,12 +103,12 @@ bool MAX17048Singleton::isExternallyPowered() float volts = cellVoltage(); if (isnan(volts)) { // if the battery is not connected then there must be external power - LOG_DEBUG("MAX17048Sensor::isExternallyPowered battery is\n"); + LOG_DEBUG("%s::isExternallyPowered battery is\n", sensorStr); return true; } // if the bus voltage is over MAX17048_BUS_POWER_VOLTS, then the external power // is assumed to be connected - LOG_DEBUG("MAX17048Sensor::isExternallyPowered %s connected\n", volts >= MAX17048_BUS_POWER_VOLTS ? "is" : "is not"); + LOG_DEBUG("%s::isExternallyPowered %s connected\n", sensorStr, volts >= MAX17048_BUS_POWER_VOLTS ? "is" : "is not"); return volts >= MAX17048_BUS_POWER_VOLTS; } diff --git a/src/modules/Telemetry/Sensor/MAX17048Sensor.h b/src/modules/Telemetry/Sensor/MAX17048Sensor.h index 20dca324c4..bd109cbb1c 100644 --- a/src/modules/Telemetry/Sensor/MAX17048Sensor.h +++ b/src/modules/Telemetry/Sensor/MAX17048Sensor.h @@ -40,6 +40,7 @@ class MAX17048Singleton : public Adafruit_MAX17048 std::queue chargeSamples; MAX17048ChargeState chargeState = IDLE; const String chargeLabels[3] = {F("idle"), F("export"), F("import")}; + const char *sensorStr = "MAX17048Sensor"; protected: MAX17048Singleton(); diff --git a/src/modules/TraceRouteModule.cpp b/src/modules/TraceRouteModule.cpp index 1f652dbf66..be82788246 100644 --- a/src/modules/TraceRouteModule.cpp +++ b/src/modules/TraceRouteModule.cpp @@ -101,7 +101,7 @@ void TraceRouteModule::appendMyIDandSNR(meshtastic_RouteDiscovery *updated, floa route[*route_count] = myNodeInfo.my_node_num; *route_count += 1; } else { - LOG_WARN("Route exceeded maximum hop limit, are you bridging networks?\n"); + LOG_WARN("Route exceeded maximum hop limit!\n"); // Are you bridging networks? } } diff --git a/src/serialization/MeshPacketSerializer.cpp b/src/serialization/MeshPacketSerializer.cpp index e00dde024c..acda94face 100644 --- a/src/serialization/MeshPacketSerializer.cpp +++ b/src/serialization/MeshPacketSerializer.cpp @@ -93,7 +93,7 @@ std::string MeshPacketSerializer::JsonSerialize(const meshtastic_MeshPacket *mp, } jsonObj["payload"] = new JSONValue(msgPayload); } else if (shouldLog) { - LOG_ERROR("Error decoding protobuf for telemetry message!\n"); + LOG_ERROR(errStr, msgType.c_str()); } break; } @@ -111,7 +111,7 @@ std::string MeshPacketSerializer::JsonSerialize(const meshtastic_MeshPacket *mp, msgPayload["role"] = new JSONValue((int)decoded->role); jsonObj["payload"] = new JSONValue(msgPayload); } else if (shouldLog) { - LOG_ERROR("Error decoding protobuf for nodeinfo message!\n"); + LOG_ERROR(errStr, msgType.c_str()); } break; } @@ -156,12 +156,12 @@ std::string MeshPacketSerializer::JsonSerialize(const meshtastic_MeshPacket *mp, } jsonObj["payload"] = new JSONValue(msgPayload); } else if (shouldLog) { - LOG_ERROR("Error decoding protobuf for position message!\n"); + LOG_ERROR(errStr, msgType.c_str()); } break; } case meshtastic_PortNum_WAYPOINT_APP: { - msgType = "position"; + msgType = "waypoint"; meshtastic_Waypoint scratch; meshtastic_Waypoint *decoded = NULL; memset(&scratch, 0, sizeof(scratch)); @@ -176,7 +176,7 @@ std::string MeshPacketSerializer::JsonSerialize(const meshtastic_MeshPacket *mp, msgPayload["longitude_i"] = new JSONValue((int)decoded->longitude_i); jsonObj["payload"] = new JSONValue(msgPayload); } else if (shouldLog) { - LOG_ERROR("Error decoding protobuf for position message!\n"); + LOG_ERROR(errStr, msgType.c_str()); } break; } @@ -202,7 +202,7 @@ std::string MeshPacketSerializer::JsonSerialize(const meshtastic_MeshPacket *mp, msgPayload["neighbors"] = new JSONValue(neighbors); jsonObj["payload"] = new JSONValue(msgPayload); } else if (shouldLog) { - LOG_ERROR("Error decoding protobuf for neighborinfo message!\n"); + LOG_ERROR(errStr, msgType.c_str()); } break; } @@ -234,7 +234,7 @@ std::string MeshPacketSerializer::JsonSerialize(const meshtastic_MeshPacket *mp, msgPayload["route"] = new JSONValue(route); jsonObj["payload"] = new JSONValue(msgPayload); } else if (shouldLog) { - LOG_ERROR("Error decoding protobuf for traceroute message!\n"); + LOG_ERROR(errStr, msgType.c_str()); } } break; @@ -261,7 +261,7 @@ std::string MeshPacketSerializer::JsonSerialize(const meshtastic_MeshPacket *mp, msgPayload["uptime"] = new JSONValue((unsigned int)decoded->uptime); jsonObj["payload"] = new JSONValue(msgPayload); } else if (shouldLog) { - LOG_ERROR("Error decoding protobuf for Paxcount message!\n"); + LOG_ERROR(errStr, msgType.c_str()); } break; } @@ -284,7 +284,7 @@ std::string MeshPacketSerializer::JsonSerialize(const meshtastic_MeshPacket *mp, jsonObj["payload"] = new JSONValue(msgPayload); } } else if (shouldLog) { - LOG_ERROR("Error decoding protobuf for RemoteHardware message!\n"); + LOG_ERROR(errStr, "RemoteHardware"); } break; } diff --git a/src/serialization/MeshPacketSerializer.h b/src/serialization/MeshPacketSerializer.h index 03860ab354..989f30fc07 100644 --- a/src/serialization/MeshPacketSerializer.h +++ b/src/serialization/MeshPacketSerializer.h @@ -2,6 +2,7 @@ #include static const char hexChars[16] = {'0', '1', '2', '3', '4', '5', '6', '7', '8', '9', 'A', 'B', 'C', 'D', 'E', 'F'}; +static const char *errStr = "Error decoding protobuf for %s message!\n"; class MeshPacketSerializer {