diff --git a/README.md b/README.md index d38d11b..01dcc1c 100644 --- a/README.md +++ b/README.md @@ -6,7 +6,7 @@ [![Status](https://img.shields.io/badge/status-beta-yellow.svg)](#install) [![License](https://img.shields.io/badge/license-AGPL--3.0--or--later-blue.svg)](LICENSE) -[![Version](https://img.shields.io/badge/version-2.0.1-success.svg)](https://github.com/ratspeak/rsDeck/releases) +[![Version](https://img.shields.io/badge/version-2.0.2-success.svg)](https://github.com/ratspeak/rsDeck/releases) [Ratspeak](https://github.com/ratspeak/Ratspeak) | [Docs](https://ratspeak.org/docs.html) | diff --git a/src/config/Config.h b/src/config/Config.h index c40ca23..2b8f1ca 100644 --- a/src/config/Config.h +++ b/src/config/Config.h @@ -6,8 +6,8 @@ #define RSDECK_VERSION_MAJOR 2 #define RSDECK_VERSION_MINOR 0 -#define RSDECK_VERSION_PATCH 1 -#define RSDECK_VERSION_STRING "2.0.1" +#define RSDECK_VERSION_PATCH 2 +#define RSDECK_VERSION_STRING "2.0.2" // --- Feature Flags --- #define HAS_DISPLAY true diff --git a/src/main.cpp b/src/main.cpp index 55227b6..ea228d9 100644 --- a/src/main.cpp +++ b/src/main.cpp @@ -58,6 +58,7 @@ #endif #include "config/UserConfig.h" #include "audio/AudioNotify.h" +#include "util/PerfTrace.h" #include #include #include @@ -1051,11 +1052,40 @@ static void bootRender() { // Legacy render kept as fallback } +static unsigned long bootTraceStartMs = 0; +static unsigned long bootTraceLastMs = 0; + +static void bootTraceBegin(unsigned long startMs) { +#if RSDECK_PERF_TRACE + bootTraceStartMs = startMs; + bootTraceLastMs = startMs; +#else + (void)startMs; +#endif +} + +static void bootTraceStage(const char* label) { +#if RSDECK_PERF_TRACE + const unsigned long now = millis(); + Serial.printf("[BOOT-PERF] %-22s +%lums total=%lums heap=%lu psram_free=%lu psram_largest=%lu\n", + label ? label : "?", + now - bootTraceLastMs, + now - bootTraceStartMs, + (unsigned long)ESP.getFreeHeap(), + (unsigned long)heap_caps_get_free_size(MALLOC_CAP_SPIRAM), + (unsigned long)heap_caps_get_largest_free_block(MALLOC_CAP_SPIRAM)); + bootTraceLastMs = now; +#else + (void)label; +#endif +} + // ============================================================================= // Setup — 26-step boot sequence // ============================================================================= void setup() { + const unsigned long setupStartMs = millis(); bool flashMounted = false; // Step 1: Power pin — CRITICAL: enables all T-Deck Plus peripherals @@ -1086,17 +1116,21 @@ void setup() { Serial.printf("[BOOT] Reset: %s (%d)\n", reasonStr, (int)reason); Serial.printf("[BOOT] Heap: %lu PSRAM: %lu\n", (unsigned long)ESP.getFreeHeap(), (unsigned long)ESP.getPsramSize()); + bootTraceBegin(setupStartMs); + bootTraceStage("serial-online"); // Dual-boot layout: re-arm the launcher so the next reset shows the chooser. auto launcherBoot = rs_deck::returnToLauncherNextBoot(); if (!launcherBoot.ok) { Serial.printf("[BOOT] Launcher return unavailable: %s\n", launcherBoot.message); } + bootTraceStage("launcher-return"); if (!psramFound() || heap_caps_get_largest_free_block(MALLOC_CAP_SPIRAM) < 1024 * 1024) { Serial.printf("[BOOT] FATAL: PSRAM unavailable or too fragmented (largest=%lu)\n", (unsigned long)heap_caps_get_largest_free_block(MALLOC_CAP_SPIRAM)); while (true) delay(1000); } + bootTraceStage("psram-check"); // Step 3: Initialize I2C bus (shared by keyboard + touchscreen) Wire.begin(I2C_SDA, I2C_SCL); @@ -1108,6 +1142,7 @@ void setup() { // Deassert all slave CS pins to prevent bus contention pinMode(LORA_CS, OUTPUT); digitalWrite(LORA_CS, HIGH); pinMode(SD_CS, OUTPUT); digitalWrite(SD_CS, HIGH); + bootTraceStage("i2c-spi"); // Mount flash before radio bring-up so persisted RF settings are used from // the first SX1262 init, instead of always booting at the US default first. @@ -1120,6 +1155,7 @@ void setup() { } // Select palette before any LVGL styles are built Theme::setScheme(userConfig.settings().themeLight ? Theme::Scheme::LIGHT : Theme::Scheme::DARK); + bootTraceStage("early-flash-config"); // Step 4: Radio + SD init BEFORE display // Radio and SD must init while SPIClass exclusively owns SPI2_HOST. @@ -1134,6 +1170,7 @@ void setup() { } else { Serial.println("[RADIO] SX1262 not detected!"); } + bootTraceStage("radio-init"); // SD card init (shared SPI, right after radio) digitalWrite(LORA_CS, HIGH); @@ -1145,6 +1182,7 @@ void setup() { } else { Serial.println("[SD] Not detected"); } + bootTraceStage("sd-probe"); // Verify radio SPI still works after SD init if (radioOnline) { @@ -1161,6 +1199,7 @@ void setup() { // SPIClass get valid device handles on the same SPI2_HOST bus. display.begin(); Serial.println("[BOOT] Display initialized (LovyanGFX direct)"); + bootTraceStage("display-init"); // Step 5.5: Initialize LVGL display driver if (!display.beginLVGL()) { @@ -1171,6 +1210,7 @@ void setup() { while (true) delay(1000); } Serial.println("[BOOT] LVGL initialized"); + bootTraceStage("lvgl-init"); // Verify radio SPI survives display init if (radioOnline) { @@ -1191,21 +1231,25 @@ void setup() { // framebuffer; the setProgress() above has now flushed the boot screen. // powerMgr at step 24 overrides with the user's configured value. display.setBrightness(128); + bootTraceStage("boot-screen-painted"); // Step 7: Touch HAL — GT911 I2C touch.begin(); lvBootScreen.setProgress(0.50f, "Touch ready"); // (LVGL boot renders via lv_timer_handler in setProgress) + bootTraceStage("touch-init"); // Step 8: Keyboard HAL — ESP32-C3 I2C keyboard.begin(); lvBootScreen.setProgress(0.52f, "Keyboard ready"); // (LVGL boot renders via lv_timer_handler in setProgress) + bootTraceStage("keyboard-init"); // Step 9: Trackball HAL — GPIO interrupts trackball.begin(); lvBootScreen.setProgress(0.54f, "Trackball ready"); // (LVGL boot renders via lv_timer_handler in setProgress) + bootTraceStage("trackball-init"); // Step 10: Input manager inputManager.begin(&keyboard, &trackball, &touch); @@ -1216,6 +1260,7 @@ void setup() { lvBootScreen.setProgress(0.55f, "Input ready"); // (LVGL boot renders via lv_timer_handler in setProgress) + bootTraceStage("input-init"); // Step 11: Register hotkeys hotkeys.registerHotkey('h', "Help", onHotkeyHelp); @@ -1234,6 +1279,7 @@ void setup() { }); lvBootScreen.setProgress(0.58f, "Hotkeys registered"); // (LVGL boot renders via lv_timer_handler in setProgress) + bootTraceStage("hotkeys"); // Step 12: Mount LittleFS lvBootScreen.setProgress(0.60f, "Mounting flash..."); @@ -1247,6 +1293,7 @@ void setup() { flashMounted = true; Serial.println("[BOOT] LittleFS mounted OK"); } + bootTraceStage("flash-mounted"); // Step 13: Boot loop detection (NVS) { @@ -1261,6 +1308,7 @@ void setup() { } } } + bootTraceStage("bootloop-nvs"); lvBootScreen.setProgress(0.64f, "Loading config..."); userConfig.load(sdStore, flash); @@ -1271,6 +1319,7 @@ void setup() { } inputManager.setTrackballSpeed(userConfig.settings().trackballSpeed); applyRadioSettingsToHardware(userConfig.settings(), "BOOT PRE-RNS"); + bootTraceStage("config-load"); lvBootScreen.setProgress(0.65f, "Starting Reticulum..."); // (LVGL boot renders via lv_timer_handler in setProgress) @@ -1283,14 +1332,17 @@ void setup() { lvBootScreen.setProgress(0.72f, "RNS: FAILED"); } // (LVGL boot renders via lv_timer_handler in setProgress) + bootTraceStage("reticulum-begin"); // Step 15.5: Identity manager identityMgr.begin(&flash, &sdStore); + bootTraceStage("identity-manager"); // Step 16: Message store lvBootScreen.setProgress(0.72f, "Starting messaging..."); // (LVGL boot renders via lv_timer_handler in setProgress) messageStore.begin(&flash, &sdStore, userConfig.settings().sdStorageEnabled); + bootTraceStage("message-store"); // Step 17: LXMF init lxmf.begin(&rns, &messageStore); @@ -1303,6 +1355,7 @@ void setup() { lxmf.unreadCount(); lvBootScreen.setProgress(0.75f, "LXMF ready"); // (LVGL boot renders via lv_timer_handler in setProgress) + bootTraceStage("lxmf-begin"); // Step 18: Announce manager lvBootScreen.setProgress(0.78f, "Loading contacts..."); @@ -1317,6 +1370,7 @@ void setup() { announceManager->loadNameCache(); announceHandler = RNS::HAnnounceHandler(announceManager); RNS::Transport::register_announce_handler(announceHandler); + bootTraceStage("contacts-cache"); // No default TCP hub. Users opt in via Settings → TCP Server → // "Ratspeak Hub" (seeds rns.ratspeak.org) or "Custom" (host/port). @@ -1342,6 +1396,7 @@ void setup() { } } } + bootTraceStage("identity-name-sync"); // Step 20: Boot loop recovery if (bootLoopRecovery) { @@ -1350,6 +1405,7 @@ void setup() { } lvBootScreen.setProgress(0.83f, "Config loaded"); // (LVGL boot renders via lv_timer_handler in setProgress) + bootTraceStage("bootloop-recovery"); // Step 21: Apply radio config if (radioOnline && userConfig.settings().loraEnabled) { @@ -1362,6 +1418,7 @@ void setup() { } lvBootScreen.setProgress(0.84f, "Radio configured"); // (LVGL boot renders via lv_timer_handler in setProgress) + bootTraceStage("radio-config"); // Step 22: WiFi start RatWiFiMode wifiMode = userConfig.settings().wifiMode; @@ -1418,6 +1475,7 @@ void setup() { lvBootScreen.setProgress(0.87f, "WiFi disabled"); // (LVGL boot renders via lv_timer_handler in setProgress) } + bootTraceStage("wifi-start"); // Step 23: BLE stays disabled in default builds. lvBootScreen.setProgress(0.90f, "Links ready"); @@ -1449,6 +1507,7 @@ void setup() { ui.lvStatusBar().setBLEActive(false); Serial.println("[BLE] Disabled in default firmware build"); #endif + bootTraceStage("links-ready"); // Step 24: Power manager lvBootScreen.setProgress(0.92f, "Power manager..."); @@ -1460,6 +1519,7 @@ void setup() { powerMgr.setKbBrightness(userConfig.settings().keyboardBrightness); powerMgr.setKbAutoOn(userConfig.settings().keyboardAutoOn); powerMgr.setKbAutoOff(userConfig.settings().keyboardAutoOff); + bootTraceStage("power-manager"); // Step 24.5: GPS init #if HAS_GPS @@ -1469,6 +1529,7 @@ void setup() { gps.setLocationEnabled(userConfig.settings().gpsLocationEnabled); gps.begin(); Serial.println("[BOOT] GPS UART started (MIA-M10Q)"); + bootTraceStage("gps-start"); } #endif @@ -1478,6 +1539,7 @@ void setup() { audio.setEnabled(userConfig.settings().audioEnabled); audio.setVolume(userConfig.settings().audioVolume); audio.begin(); + bootTraceStage("audio-init"); // Boot complete — transition to Home screen // Yield to LVGL instead of blocking delay @@ -1485,6 +1547,7 @@ void setup() { for (int i = 0; i < 6; i++) { lv_timer_handler(); delay(1); } lvBootScreen.setProgress(1.0f, "Ready"); audio.playBoot(); + bootTraceStage("boot-ready-screen"); bootComplete = true; @@ -1535,14 +1598,14 @@ void setup() { lvHomeScreen.setTCPToggleCallback([]() { auto& s = userConfig.settings(); bool enabled = false; - bool hasSavedRelay = false; + bool hasSavedTcpServer = false; for (const auto& ep : s.tcpConnections) { - if (!ep.host.isEmpty()) hasSavedRelay = true; + if (!ep.host.isEmpty()) hasSavedTcpServer = true; if (!ep.host.isEmpty() && ep.autoConnect) { enabled = true; break; } } if (enabled) { for (auto& ep : s.tcpConnections) ep.autoConnect = false; - } else if (hasSavedRelay) { + } else if (hasSavedTcpServer) { for (auto& ep : s.tcpConnections) { if (!ep.host.isEmpty()) ep.autoConnect = true; } @@ -1556,9 +1619,9 @@ void setup() { } bool ok = userConfig.save(sdStore, flash); ui.lvStatusBar().showToast( - ok ? "TCP relay saved; reboot to apply" : "Save failed", + ok ? "TCP server saved; reboot to apply" : "Save failed", ok ? 3000 : 2000); - Serial.printf("[TCP] Saved relay %s (save %s, reboot required)\n", + Serial.printf("[TCP] Saved server %s (save %s, reboot required)\n", enabled ? "OFF" : "ON", ok ? "OK" : "FAILED"); }); @@ -1720,6 +1783,7 @@ void setup() { ui.lvTabBar().setTabCallback([](int tab) { if (lvTabScreens[tab]) ui.setScreen(lvTabScreens[tab]); }); + bootTraceStage("screen-wiring"); // Data clean screen (first boot only — when SD has old data) lvDataCleanScreen.setDoneCallback([](bool wipe) { @@ -1839,6 +1903,7 @@ void setup() { // Everything configured — go straight to home goHome(); } + bootTraceStage("boot-routing"); // Clear boot loop counter — we survived! { @@ -1848,17 +1913,20 @@ void setup() { prefs.end(); } } + bootTraceStage("bootcounter-clear"); if (userConfig.settings().keyboardAutoOn) { // We are in ACTIVE power state here, switch keyboard backlight ON keyboard.backlightOn(); } + bootTraceStage("keyboard-auto"); Serial.println("[BOOT] rsDeck ready"); Serial.printf("[BOOT] Summary: radio=%s flash=%s sd=%s\n", radioOnline ? "ONLINE" : "OFFLINE", flash.isReady() ? "OK" : "FAIL", sdStore.isReady() ? "OK" : "FAIL"); + bootTraceStage("setup-complete"); } // ============================================================================= diff --git a/src/reticulum/AnnounceManager.cpp b/src/reticulum/AnnounceManager.cpp index e6bb272..c2cb935 100644 --- a/src/reticulum/AnnounceManager.cpp +++ b/src/reticulum/AnnounceManager.cpp @@ -4,6 +4,7 @@ #include "storage/SDStore.h" #include "storage/FlashStore.h" #include "transport/LoRaInterface.h" +#include "util/PerfTrace.h" #include #include @@ -279,9 +280,11 @@ void AnnounceManager::persistKnownDestinationsAfterAnnounce(const char* reason, } _lastKnownDestinationsPersist = now; + unsigned long startMs = millis(); RNS::Identity::persist_data(); - Serial.printf("[ANNOUNCE] Known destinations persisted after %s\n", - reason ? reason : "announce"); + unsigned long elapsed = millis() - startMs; + Serial.printf("[ANNOUNCE] Known destinations persisted after %s (force=%s in %lums)\n", + reason ? reason : "announce", force ? "yes" : "no", elapsed); } int AnnounceManager::nodesOnlineSince(unsigned long maxAgeMs) const { @@ -470,19 +473,36 @@ std::string AnnounceManager::lookupName(const std::string& hexHash) const { } void AnnounceManager::saveNameCache() { + unsigned long startMs = millis(); JsonDocument doc; for (auto& kv : _nameCache) { doc[kv.first] = kv.second; } String json; + unsigned long serializeStartMs = millis(); serializeJson(doc, json); + unsigned long serializeMs = millis() - serializeStartMs; + size_t bytes = json.length(); + bool sdOk = false; + bool flashOk = false; + unsigned long sdMs = 0; + unsigned long flashMs = 0; if (_sd && _sd->isReady()) { - _sd->writeString("/ratdeck/config/names.json", json); + unsigned long writeStartMs = millis(); + sdOk = _sd->writeString("/ratdeck/config/names.json", json); + sdMs = millis() - writeStartMs; } if (_flash) { - _flash->writeString("/config/names.json", json); + unsigned long writeStartMs = millis(); + flashOk = _flash->writeString("/config/names.json", json); + flashMs = millis() - writeStartMs; } - Serial.printf("[ANNOUNCE] Name cache saved (%d entries)\n", (int)_nameCache.size()); + unsigned long elapsed = millis() - startMs; + Serial.printf("[ANNOUNCE] Name cache saved (%d entries, bytes=%u, serialize=%lums sd=%s/%lums flash=%s/%lums total=%lums)\n", + (int)_nameCache.size(), (unsigned)bytes, serializeMs, + (_sd && _sd->isReady()) ? (sdOk ? "ok" : "fail") : "skip", sdMs, + _flash ? (flashOk ? "ok" : "fail") : "skip", flashMs, + elapsed); } void AnnounceManager::loadNameCache() { diff --git a/src/reticulum/LXMFManager.cpp b/src/reticulum/LXMFManager.cpp index 2965c9d..b9292a9 100644 --- a/src/reticulum/LXMFManager.cpp +++ b/src/reticulum/LXMFManager.cpp @@ -22,11 +22,11 @@ bool LXMFManager::begin(ReticulumManager* rns, MessageStore* store) { dest.set_packet_callback(onPacketReceived); dest.set_link_established_callback(onLinkEstablished); if (_store) { - for (const auto& id : _store->loadRecentMessageIds(MAX_SEEN_IDS)) { + for (const auto& id : _store->startupRecentMessageIds(MAX_SEEN_IDS)) { rememberMessageId(id); } - std::vector pending = _store->loadPendingOutgoing(); - for (auto& msg : pending) { + const std::vector& pending = _store->startupPendingOutgoing(); + for (auto msg : pending) { if ((int)_outQueue.size() >= RSDECK_MAX_OUTQUEUE) break; msg.lastRetryMs = 0; _outQueue.push_back(msg); @@ -508,6 +508,11 @@ std::vector LXMFManager::getMessages(const std::string& peerHex) co return {}; } +std::vector LXMFManager::getRecentMessages(const std::string& peerHex, size_t maxMessages) const { + if (_store) return _store->loadConversationTail(peerHex, maxMessages); + return {}; +} + int LXMFManager::unreadCount(const std::string& peerHex) const { if (!_store) return 0; if (peerHex.empty()) return _store->totalUnreadCount(); diff --git a/src/reticulum/LXMFManager.h b/src/reticulum/LXMFManager.h index d4c6978..ac307f7 100644 --- a/src/reticulum/LXMFManager.h +++ b/src/reticulum/LXMFManager.h @@ -35,6 +35,7 @@ public: uint32_t storeRevision() const { return _store ? _store->revision() : 0; } const std::vector& conversations() const; std::vector getMessages(const std::string& peerHex) const; + std::vector getRecentMessages(const std::string& peerHex, size_t maxMessages) const; int unreadCount(const std::string& peerHex = "") const; void markRead(const std::string& peerHex); bool deleteConversation(const std::string& peerHex); diff --git a/src/reticulum/ReticulumManager.cpp b/src/reticulum/ReticulumManager.cpp index 12f59b2..37be62c 100644 --- a/src/reticulum/ReticulumManager.cpp +++ b/src/reticulum/ReticulumManager.cpp @@ -1,8 +1,10 @@ // Direct port from Ratputer — microReticulum integration #include "ReticulumManager.h" #include "config/Config.h" +#include "util/PerfTrace.h" #include #include +#include #include #include @@ -22,6 +24,7 @@ size_t LittleFSFileSystem::read_file(const char* p, RNS::Bytes& data) { } size_t LittleFSFileSystem::write_file(const char* p, const RNS::Bytes& data) { + unsigned long startMs = PerfTrace::nowMs(); String path = String(p); int lastSlash = path.lastIndexOf('/'); if (lastSlash > 0) { @@ -29,9 +32,13 @@ size_t LittleFSFileSystem::write_file(const char* p, const RNS::Bytes& data) { if (!LittleFS.exists(dir.c_str())) { LittleFS.mkdir(dir.c_str()); } } File f = LittleFS.open(p, "w"); - if (!f) return 0; + if (!f) { + PerfTrace::write("flash", "rns-write", p, data.size(), startMs, false); + return 0; + } size_t w = f.write(data.data(), data.size()); f.close(); + PerfTrace::write("flash", "rns-write", p, data.size(), startMs, w == data.size()); return w; } @@ -74,19 +81,29 @@ bool copyFlashToSD(SDStore* sd, const char* flashPath, const char* sdPath) { if (!sd || !sd->isReady()) return false; File in = LittleFS.open(flashPath, "r"); if (!in || in.size() == 0) { if (in) in.close(); return false; } + unsigned long startMs = PerfTrace::nowMs(); + size_t copiedBytes = 0; String path = String(sdPath); int lastSlash = path.lastIndexOf('/'); if (lastSlash > 0) { String dir = path.substring(0, lastSlash); - if (!sd->ensureDir(dir.c_str())) { in.close(); return false; } + if (!sd->ensureDir(dir.c_str())) { + in.close(); + PerfTrace::write("sd", "rns-copy", sdPath, copiedBytes, startMs, false); + return false; + } } String tmpPath = path + ".tmp"; String bakPath = path + ".bak"; SD.remove(tmpPath.c_str()); File out = SD.open(tmpPath.c_str(), FILE_WRITE); - if (!out) { in.close(); return false; } + if (!out) { + in.close(); + PerfTrace::write("sd", "rns-copy", sdPath, copiedBytes, startMs, false); + return false; + } uint8_t buf[RNS_COPY_CHUNK]; bool ok = true; @@ -94,12 +111,17 @@ bool copyFlashToSD(SDStore* sd, const char* flashPath, const char* sdPath) { size_t n = in.read(buf, sizeof(buf)); if (n == 0) break; if (out.write(buf, n) != n) { ok = false; break; } + copiedBytes += n; RNS::Utilities::OS::reset_watchdog(); } in.close(); out.close(); - if (!ok) { SD.remove(tmpPath.c_str()); return false; } + if (!ok) { + SD.remove(tmpPath.c_str()); + PerfTrace::write("sd", "rns-copy", sdPath, copiedBytes, startMs, false); + return false; + } if (SD.exists(sdPath)) { SD.remove(bakPath.c_str()); SD.rename(sdPath, bakPath.c_str()); @@ -108,24 +130,53 @@ bool copyFlashToSD(SDStore* sd, const char* flashPath, const char* sdPath) { if (!SD.rename(tmpPath.c_str(), sdPath)) { if (SD.exists(bakPath.c_str())) SD.rename(bakPath.c_str(), sdPath); SD.remove(tmpPath.c_str()); + PerfTrace::write("sd", "rns-copy", sdPath, copiedBytes, startMs, false); return false; } SD.remove(bakPath.c_str()); + PerfTrace::write("sd", "rns-copy", sdPath, copiedBytes, startMs, true); return true; } class LittleFSStreamImpl : public RNS::FileStreamImpl { public: - LittleFSStreamImpl(File&& f) : _f(std::move(f)) {} - ~LittleFSStreamImpl() override { if (_f) _f.close(); } + LittleFSStreamImpl(File&& f, const char* path, RNS::FileStream::MODE mode) + : _f(std::move(f)), _mode(mode), _startMs(PerfTrace::nowMs()) { + strncpy(_path, path ? path : "?", sizeof(_path) - 1); + _path[sizeof(_path) - 1] = '\0'; + } + ~LittleFSStreamImpl() override { close(); } protected: - const char* name() override { return _f ? _f.name() : ""; } + const char* name() override { return _path; } size_t size() override { return _f ? _f.size() : 0; } - void close() override { if (_f) _f.close(); } + void close() override { + if (!_f) return; + if (!_logged && _mode != RNS::FileStream::MODE_READ) { + PerfTrace::write("flash", + _mode == RNS::FileStream::MODE_APPEND ? "rns-stream-append" : "rns-stream", + _path, _bytesWritten, _startMs, !_writeFailed); + _logged = true; + } + _f.close(); + } - size_t write(uint8_t byte) override { return _f ? _f.write(byte) : 0; } - size_t write(const uint8_t* buffer, size_t len) override { return _f ? _f.write(buffer, len) : 0; } + size_t write(uint8_t byte) override { + size_t written = _f ? _f.write(byte) : 0; + if (_mode != RNS::FileStream::MODE_READ) { + _bytesWritten += written; + if (written != 1) _writeFailed = true; + } + return written; + } + size_t write(const uint8_t* buffer, size_t len) override { + size_t written = _f ? _f.write(buffer, len) : 0; + if (_mode != RNS::FileStream::MODE_READ) { + _bytesWritten += written; + if (written != len) _writeFailed = true; + } + return written; + } int available() override { return _f ? _f.available() : 0; } int read() override { return _f ? _f.read() : -1; } @@ -134,6 +185,12 @@ protected: private: File _f; + RNS::FileStream::MODE _mode; + unsigned long _startMs = 0; + size_t _bytesWritten = 0; + bool _writeFailed = false; + bool _logged = false; + char _path[64] = {}; }; } // namespace @@ -150,7 +207,7 @@ RNS::FileStream LittleFSFileSystem::open_file(const char* path, RNS::FileStream: } File f = LittleFS.open(path, openMode); if (!f) return {RNS::Type::NONE}; - return RNS::FileStream(new LittleFSStreamImpl(std::move(f))); + return RNS::FileStream(new LittleFSStreamImpl(std::move(f), path, mode)); } bool LittleFSFileSystem::remove_file(const char* p) { return LittleFS.remove(p); } bool LittleFSFileSystem::rename_file(const char* f, const char* t) { return LittleFS.rename(f, t); } @@ -359,20 +416,37 @@ void ReticulumManager::loop() { // node, so path tables are intentionally not persisted across boots. void ReticulumManager::persistData() { unsigned long start = millis(); + unsigned long identityPersistMs = 0; + unsigned long sdMirrorMs = 0; + size_t sdMirrorBytes = 0; + bool sdMirrorAttempted = false; + bool sdMirrorOk = false; + const char* cycleName = "identity"; switch (_persistCycle) { case 0: + { + unsigned long phaseMs = millis(); RNS::Identity::persist_data(); + identityPersistMs = millis() - phaseMs; break; + } case 1: + cycleName = "sd-mirror"; if (_sd && _sd->isReady()) { static const char* files[] = {"/known_destinations"}; for (const char* name : files) { File f = LittleFS.open(name, "r"); if (f && f.size() > 0) { + size_t len = f.size(); f.close(); char sdPath[64]; snprintf(sdPath, sizeof(sdPath), "/ratdeck/transport%s", name); - copyFlashToSD(_sd, name, sdPath); + unsigned long phaseMs = millis(); + bool ok = copyFlashToSD(_sd, name, sdPath); + sdMirrorMs += millis() - phaseMs; + sdMirrorBytes += ok ? len : 0; + sdMirrorAttempted = true; + sdMirrorOk = sdMirrorOk || ok; } else { if (f) f.close(); } @@ -381,7 +455,10 @@ void ReticulumManager::persistData() { break; } unsigned long dur = millis() - start; - Serial.printf("[PERSIST] Cycle %d done (%lums)\n", _persistCycle, dur); + Serial.printf("[PERSIST] Cycle %d %s done total=%lums identity=%lums sd_copy=%lums sd_bytes=%u sd=%s\n", + _persistCycle, cycleName, dur, identityPersistMs, sdMirrorMs, + (unsigned)sdMirrorBytes, + sdMirrorAttempted ? (sdMirrorOk ? "ok" : "fail") : "skip"); if (dur > 500) { Serial.printf("[PERSIST] WARNING: Cycle %d blocked for %lums!\n", _persistCycle, dur); } diff --git a/src/storage/FlashStore.cpp b/src/storage/FlashStore.cpp index 61b70c3..aabc257 100644 --- a/src/storage/FlashStore.cpp +++ b/src/storage/FlashStore.cpp @@ -1,4 +1,5 @@ #include "FlashStore.h" +#include "util/PerfTrace.h" bool FlashStore::begin() { // Legacy standalone builds label this partition "littlefs"; bmorcelli/Launcher @@ -71,17 +72,25 @@ bool FlashStore::remove(const char* path) { } bool FlashStore::writeAtomic(const char* path, const uint8_t* data, size_t len) { - if (!_ready) return false; + unsigned long startMs = PerfTrace::nowMs(); + if (!_ready) { + PerfTrace::write("flash", "atomic", path, len, startMs, false); + return false; + } String tmpPath = String(path) + ".tmp"; String bakPath = String(path) + ".bak"; File f = LittleFS.open(tmpPath.c_str(), "w"); - if (!f) return false; + if (!f) { + PerfTrace::write("flash", "atomic", path, len, startMs, false); + return false; + } size_t written = f.write(data, len); f.close(); if (written != len) { LittleFS.remove(tmpPath.c_str()); + PerfTrace::write("flash", "atomic", path, len, startMs, false); return false; } @@ -89,6 +98,7 @@ bool FlashStore::writeAtomic(const char* path, const uint8_t* data, size_t len) if (!verify || verify.size() != len) { if (verify) verify.close(); LittleFS.remove(tmpPath.c_str()); + PerfTrace::write("flash", "atomic", path, len, startMs, false); return false; } verify.close(); @@ -102,12 +112,14 @@ bool FlashStore::writeAtomic(const char* path, const uint8_t* data, size_t len) if (LittleFS.exists(bakPath.c_str())) { LittleFS.rename(bakPath.c_str(), path); } + PerfTrace::write("flash", "atomic", path, len, startMs, false); return false; } // Clean up backup file after successful write LittleFS.remove(bakPath.c_str()); + PerfTrace::write("flash", "atomic", path, len, startMs, true); return true; } diff --git a/src/storage/MessageStore.cpp b/src/storage/MessageStore.cpp index 41c2645..ca518ed 100644 --- a/src/storage/MessageStore.cpp +++ b/src/storage/MessageStore.cpp @@ -1,5 +1,6 @@ #include "MessageStore.h" #include "config/Config.h" +#include "util/PerfTrace.h" #include #include #include @@ -54,10 +55,13 @@ bool MessageStore::begin(FlashStore* flash, SDStore* sd, bool externalStorageEna buildSummaries(); unsigned long summaryMs = millis() - phaseMs; unsigned long totalMs = millis() - beginMs; - if (totalMs > 100 || summaryMs > 50) { - Serial.printf("[PERF] MSG begin: total=%lums migrate=%lums trunc=%lums counter=%lums refresh=%lums summaries=%lums\n", - totalMs, migrateMs, truncMs, counterMs, refreshMs, summaryMs); - } +#if RSDECK_PERF_TRACE + Serial.printf("[PERF] MSG begin: total=%lums migrate=%lums trunc=%lums counter=%lums refresh=%lums summaries=%lums convs=%d summary_count=%d ext=%s sd=%s\n", + totalMs, migrateMs, truncMs, counterMs, refreshMs, summaryMs, + (int)_conversations.size(), (int)_summaries.size(), + _externalStorageEnabled ? "on" : "off", + (_sd && _sd->isReady()) ? "ready" : "no"); +#endif Serial.printf("[MSGSTORE] %d conversations found, receive counter=%lu\n", (int)_conversations.size(), (unsigned long)_nextReceiveCounter); return true; @@ -286,6 +290,7 @@ bool MessageStore::saveMessage(LXMFMessage& msg) { std::string peerHex = msg.incoming ? msg.sourceHash.toHex() : msg.destHash.toHex(); + unsigned long serializeStartMs = millis(); JsonDocument doc; doc["src"] = msg.sourceHash.toHex(); doc["dst"] = msg.destHash.toHex(); @@ -301,6 +306,8 @@ bool MessageStore::saveMessage(LXMFMessage& msg) { String json; serializeJson(doc, json); + unsigned long serializeMs = millis() - serializeStartMs; + size_t jsonBytes = json.length(); // Counter-based filename: unique, monotonic, sorts correctly uint32_t counter = _nextReceiveCounter++; @@ -310,27 +317,37 @@ bool MessageStore::saveMessage(LXMFMessage& msg) { (unsigned long)counter, msg.incoming ? 'i' : 'o'); // Persist counter to NVS + unsigned long nvsStartMs = millis(); { Preferences p; p.begin("ratdeck_msg", false); p.putUInt("msgctr", _nextReceiveCounter); p.end(); } + unsigned long nvsMs = millis() - nvsStartMs; bool sdOk = false; bool flashOk = false; + bool sdAttempted = false; + unsigned long sdMs = 0; + unsigned long flashMs = 0; if (_externalStorageEnabled && _sd && _sd->isReady()) { + sdAttempted = true; + unsigned long sdStartMs = millis(); String sdDir = sdConversationDir(peerHex); _sd->ensureDir(sdDir.c_str()); String sdPath = sdDir + "/" + filename; sdOk = _sd->writeString(sdPath.c_str(), json); + sdMs = millis() - sdStartMs; } + unsigned long flashStartMs = millis(); String flashDir = conversationDir(peerHex); _flash->ensureDir(flashDir.c_str()); String flashPath = flashDir + "/" + filename; flashOk = _flash->writeString(flashPath.c_str(), json); + flashMs = millis() - flashStartMs; bool saved = sdOk || flashOk; bool found = false; @@ -339,10 +356,13 @@ bool MessageStore::saveMessage(LXMFMessage& msg) { } if (!found) _conversations.push_back(peerHex); + unsigned long enforceStartMs = millis(); if (sdOk) enforceSDLimit(peerHex); if (flashOk) enforceFlashLimit(peerHex); + unsigned long enforceMs = millis() - enforceStartMs; // Update summary cache + unsigned long summaryStartMs = millis(); { auto& s = _summaries[peerHex]; s.lastTimestamp = msg.timestamp; @@ -368,24 +388,46 @@ bool MessageStore::saveMessage(LXMFMessage& msg) { rebuildSummary(peerHex); } } + unsigned long summaryMs = millis() - summaryStartMs; if (saved) bumpRevision(); unsigned long elapsed = millis() - startMs; - if (elapsed > 30) { - Serial.printf("[PERF] MSG save: %s dir=%c sd=%s flash=%s in %lums\n", + if (PerfTrace::shouldLog(elapsed, RSDECK_PERF_MSG_TRACE_MS) || + PerfTrace::shouldLog(sdMs, RSDECK_PERF_WRITE_TRACE_MS) || + PerfTrace::shouldLog(flashMs, RSDECK_PERF_WRITE_TRACE_MS) || + !saved) { + Serial.printf("[PERF] MSG save: peer=%s dir=%c bytes=%u counter=%lu sd=%s/%lums flash=%s/%lums serialize=%lums nvs=%lums enforce=%lums summary=%lums total=%lums\n", peerHex.substr(0, 8).c_str(), msg.incoming ? 'i' : 'o', - sdOk ? "ok" : "no", flashOk ? "ok" : "no", - (unsigned long)elapsed); + (unsigned)jsonBytes, (unsigned long)counter, + sdAttempted ? (sdOk ? "ok" : "fail") : "skip", sdMs, + flashOk ? "ok" : "fail", flashMs, + serializeMs, nvsMs, enforceMs, summaryMs, elapsed); } return saved; } std::vector MessageStore::loadConversation(const std::string& peerHex) const { - std::vector messages; + return loadConversationTail(peerHex, 0); +} - auto loadFromDir = [&](File& d, auto readFileFn) { +std::vector MessageStore::loadConversationTail(const std::string& peerHex, size_t maxMessages) const { + std::vector messages; + unsigned long startMs = millis(); + unsigned long collectMs = 0; + unsigned long sortMs = 0; + unsigned long readMs = 0; + unsigned long parseMs = 0; + int filesSeen = 0; + int parsedMessages = 0; + int parseFailures = 0; + size_t bytesRead = 0; + const char* backend = "none"; + + auto loadFromDir = [&](File& d, auto readFileFn, const char* source) { + backend = source; // Collect filenames first, then sort alphabetically (counter prefix = insertion order) std::vector filenames; + unsigned long phaseMs = millis(); File entry = d.openNextFile(); while (entry) { if (!entry.isDirectory() && isJsonFile(entry.name())) { @@ -393,13 +435,30 @@ std::vector MessageStore::loadConversation(const std::string& peerH } entry = d.openNextFile(); } - std::sort(filenames.begin(), filenames.end()); + collectMs += millis() - phaseMs; + filesSeen += (int)filenames.size(); - for (const auto& fname : filenames) { + phaseMs = millis(); + std::sort(filenames.begin(), filenames.end()); + sortMs += millis() - phaseMs; + + size_t startIndex = 0; + if (maxMessages > 0 && filenames.size() > maxMessages) { + startIndex = filenames.size() - maxMessages; + } + + for (size_t i = startIndex; i < filenames.size(); i++) { + const auto& fname = filenames[i]; + unsigned long readStartMs = millis(); String json = readFileFn(fname); + readMs += millis() - readStartMs; if (json.length() == 0) continue; + bytesRead += json.length(); JsonDocument doc; - if (!deserializeJson(doc, json)) { + unsigned long parseStartMs = millis(); + DeserializationError err = deserializeJson(doc, json); + parseMs += millis() - parseStartMs; + if (!err) { LXMFMessage msg; std::string srcHex = doc["src"] | ""; std::string dstHex = doc["dst"] | ""; @@ -424,6 +483,9 @@ std::vector MessageStore::loadConversation(const std::string& peerH msg.messageId.assignHex(msgIdHex.c_str()); } messages.push_back(msg); + parsedMessages++; + } else { + parseFailures++; } } }; @@ -436,7 +498,7 @@ std::vector MessageStore::loadConversation(const std::string& peerH loadFromDir(d, [&](const String& fname) { String path = sdDir + "/" + fname; return _sd->readString(path.c_str()); - }); + }, "sd"); loadedFromSD = true; } } @@ -453,10 +515,17 @@ std::vector MessageStore::loadConversation(const std::string& peerH if (size > 0 && size < 4096) return f.readString(); } return String(""); - }); + }, "flash"); } } + unsigned long elapsed = millis() - startMs; + if (PerfTrace::shouldLog(elapsed, RSDECK_PERF_MSG_TRACE_MS) || filesSeen > 64) { + Serial.printf("[PERF] MSG loadConversation: peer=%s backend=%s files=%d msgs=%d cap=%u bytes=%u collect=%lums sort=%lums read=%lums parse=%lums parse_fail=%d total=%lums\n", + peerHex.substr(0, 8).c_str(), backend, filesSeen, + parsedMessages, (unsigned)maxMessages, (unsigned)bytesRead, + collectMs, sortMs, readMs, parseMs, parseFailures, elapsed); + } return messages; } @@ -569,11 +638,19 @@ void MessageStore::markConversationRead(const std::string& peerHex) { unsigned long startMs = millis(); int scannedFiles = 0; int rewrittenFiles = 0; - auto markInDir = [&](auto openFn, auto writeFn, const String& dir) { + int sdWrites = 0; + int flashWrites = 0; + size_t rewrittenBytes = 0; + unsigned long collectMs = 0; + unsigned long readMs = 0; + unsigned long parseMs = 0; + unsigned long writeMs = 0; + auto markInDir = [&](auto openFn, auto writeFn, const String& dir, const char* backend) { // Collect only incoming (_i.json) filenames std::vector incomingFiles; File d = openFn(dir.c_str()); if (!d || !d.isDirectory()) return; + unsigned long phaseMs = millis(); File entry = d.openNextFile(); while (entry) { if (!entry.isDirectory() && isJsonFile(entry.name())) { @@ -585,6 +662,7 @@ void MessageStore::markConversationRead(const std::string& peerHex) { } entry = d.openNextFile(); } + collectMs += millis() - phaseMs; // Sort descending (newest first) to stop early at first already-read std::sort(incomingFiles.begin(), incomingFiles.end(), @@ -594,24 +672,34 @@ void MessageStore::markConversationRead(const std::string& peerHex) { String path = dir + "/" + fname; // Read file via the appropriate storage String json; + unsigned long readStartMs = millis(); File f = openFn(path.c_str()); if (f && !f.isDirectory()) { size_t size = f.size(); if (size > 0 && size < 4096) json = f.readString(); f.close(); } + readMs += millis() - readStartMs; if (json.length() == 0) continue; scannedFiles++; JsonDocument doc; - if (deserializeJson(doc, json)) continue; + unsigned long parseStartMs = millis(); + DeserializationError err = deserializeJson(doc, json); + parseMs += millis() - parseStartMs; + if (err) continue; bool isRead = doc["read"] | false; if (isRead) break; // all older must be read too doc["read"] = true; String updated; serializeJson(doc, updated); + unsigned long writeStartMs = millis(); writeFn(path.c_str(), updated); + writeMs += millis() - writeStartMs; + rewrittenBytes += updated.length(); rewrittenFiles++; + if (backend && backend[0] == 's') sdWrites++; + else flashWrites++; } }; @@ -619,14 +707,14 @@ void MessageStore::markConversationRead(const std::string& peerHex) { String sdDir = sdConversationDir(peerHex); markInDir([&](const char* p) { return _sd->openDir(p); }, [&](const char* p, const String& d) { _sd->writeString(p, d); return true; }, - sdDir); + sdDir, "sd"); } if (_flash) { String dir = conversationDir(peerHex); markInDir([](const char* p) { return LittleFS.open(p); }, [&](const char* p, const String& d) { _flash->writeString(p, d); return true; }, - dir); + dir, "flash"); } bool changed = false; @@ -640,10 +728,11 @@ void MessageStore::markConversationRead(const std::string& peerHex) { } if (changed) bumpRevision(); unsigned long elapsed = millis() - startMs; - if (elapsed > 25) { - Serial.printf("[PERF] MSG markRead: %s scanned=%d wrote=%d in %lums\n", + if (PerfTrace::shouldLog(elapsed, RSDECK_PERF_MSG_TRACE_MS) || rewrittenFiles > 0) { + Serial.printf("[PERF] MSG markRead: peer=%s scanned=%d wrote=%d sd_writes=%d flash_writes=%d bytes=%u collect=%lums read=%lums parse=%lums write=%lums total=%lums\n", peerHex.substr(0, 8).c_str(), scannedFiles, rewrittenFiles, - (unsigned long)elapsed); + sdWrites, flashWrites, (unsigned)rewrittenBytes, + collectMs, readMs, parseMs, writeMs, elapsed); } } @@ -773,7 +862,10 @@ bool MessageStore::updateMessageStatusByCounter(const std::string& peerHex, uint return updated; } -ConversationSummary MessageStore::buildSummaryForPeer(const std::string& peerHex) const { +ConversationSummary MessageStore::buildSummaryForPeer( + const std::string& peerHex, + std::vector* pendingOut, + std::vector>* recentIds) const { unsigned long startMs = millis(); ConversationSummary summary; @@ -810,6 +902,7 @@ ConversationSummary MessageStore::buildSummaryForPeer(const std::string& peerHex std::sort(files.begin(), files.end()); String basePath = loadedFromSD ? sdConversationDir(peerHex) : conversationDir(peerHex); + const bool collectStartup = pendingOut || recentIds; auto readJsonFile = [&](const String& path) -> String { if (loadedFromSD && _sd && _sd->isReady()) return _sd->readString(path.c_str()); @@ -817,20 +910,7 @@ ConversationSummary MessageStore::buildSummaryForPeer(const std::string& peerHex return String(""); }; - String lastPath = basePath + "/" + files.back(); - String json = readJsonFile(lastPath); - if (json.length() > 0) { - JsonDocument doc; - if (!deserializeJson(doc, json)) { - summary.lastTimestamp = doc["ts"] | 0.0; - std::string content = doc["content"] | ""; - summary.lastIncoming = doc["incoming"] | false; - std::string prefix = summary.lastIncoming ? "Them: " : "You: "; - if (content.size() > 15) content = content.substr(0, 15) + "..."; - summary.lastPreview = prefix + content; - } - } - + bool lastDone = false; bool unreadDone = false; for (int i = (int)files.size() - 1; i >= 0; i--) { const String& fname = files[i]; @@ -838,13 +918,32 @@ ConversationSummary MessageStore::buildSummaryForPeer(const std::string& peerHex const bool outgoingFile = hasDirectionSuffix(fname, 'o'); const bool needIncoming = incomingFile && !unreadDone; const bool needOutgoing = outgoingFile; - if (!needIncoming && !needOutgoing) continue; + const bool needLast = !lastDone; + if (!collectStartup && !needLast && !needIncoming && !needOutgoing) continue; String fjson = readJsonFile(basePath + "/" + fname); if (fjson.length() == 0) continue; JsonDocument fdoc; if (deserializeJson(fdoc, fjson)) continue; + uint32_t counter = counterFromFilename(fname); + + if (needLast) { + summary.lastTimestamp = fdoc["ts"] | 0.0; + std::string content = fdoc["content"] | ""; + summary.lastIncoming = fdoc["incoming"] | false; + std::string prefix = summary.lastIncoming ? "Them: " : "You: "; + if (content.size() > 15) content = content.substr(0, 15) + "..."; + summary.lastPreview = prefix + content; + lastDone = true; + } + + if (recentIds) { + std::string msgIdHex = fdoc["msgid"] | ""; + if (!msgIdHex.empty()) { + recentIds->push_back({counter, msgIdHex}); + } + } if (needIncoming) { bool isRead = fdoc["read"] | false; @@ -857,11 +956,37 @@ ConversationSummary MessageStore::buildSummaryForPeer(const std::string& peerHex if (!summary.hasOutgoing) { summary.hasOutgoing = true; summary.lastOutgoingStatus = status; - summary.lastOutgoingCounter = counterFromFilename(fname); + summary.lastOutgoingCounter = counter; } if (isPendingStatus(status)) { summary.hasPending = true; if (summary.pendingCount < UINT16_MAX) summary.pendingCount++; + if (pendingOut) { + LXMFMessage msg; + std::string srcHex = fdoc["src"] | ""; + std::string dstHex = fdoc["dst"] | ""; + if (!srcHex.empty()) { + msg.sourceHash = RNS::Bytes(); + msg.sourceHash.assignHex(srcHex.c_str()); + } + if (!dstHex.empty()) { + msg.destHash = RNS::Bytes(); + msg.destHash.assignHex(dstHex.c_str()); + } + msg.timestamp = fdoc["ts"] | 0.0; + msg.content = fdoc["content"] | ""; + msg.title = fdoc["title"] | ""; + msg.incoming = fdoc["incoming"] | false; + msg.status = status; + msg.read = fdoc["read"] | false; + msg.savedCounter = counter; + std::string msgIdHex = fdoc["msgid"] | ""; + if (!msgIdHex.empty()) { + msg.messageId = RNS::Bytes(); + msg.messageId.assignHex(msgIdHex.c_str()); + } + pendingOut->push_back(msg); + } } if (status == LXMFStatus::FAILED) { summary.hasFailed = true; @@ -915,14 +1040,38 @@ void MessageStore::updateSummaryStatus(const std::string& peerHex, uint32_t coun void MessageStore::buildSummaries() { _summaries.clear(); + _startupPendingOutgoing.clear(); + _startupRecentMessageIds.clear(); + std::vector> recentIds; for (const auto& peerHex : _conversations) { - _summaries[peerHex] = buildSummaryForPeer(peerHex); + _summaries[peerHex] = buildSummaryForPeer(peerHex, &_startupPendingOutgoing, &recentIds); yield(); } + std::sort(_startupPendingOutgoing.begin(), _startupPendingOutgoing.end(), + [](const LXMFMessage& a, const LXMFMessage& b) { + return a.savedCounter < b.savedCounter; + }); + + std::sort(recentIds.begin(), recentIds.end(), + [](const auto& a, const auto& b) { return a.first < b.first; }); + std::set seen; + for (const auto& item : recentIds) { + if (seen.insert(item.second).second) _startupRecentMessageIds.push_back(item.second); + } + Serial.printf("[MSGSTORE] Built summaries for %d conversations\n", (int)_summaries.size()); } +std::vector MessageStore::startupRecentMessageIds(size_t maxIds) const { + if (maxIds == 0 || _startupRecentMessageIds.size() <= maxIds) { + return _startupRecentMessageIds; + } + return std::vector( + _startupRecentMessageIds.end() - maxIds, + _startupRecentMessageIds.end()); +} + const ConversationSummary* MessageStore::getSummary(const std::string& peerHex) const { auto it = _summaries.find(peerHex); return (it != _summaries.end()) ? &it->second : nullptr; diff --git a/src/storage/MessageStore.h b/src/storage/MessageStore.h index 676bb21..5097cee 100644 --- a/src/storage/MessageStore.h +++ b/src/storage/MessageStore.h @@ -8,6 +8,7 @@ #include #include #include +#include struct ConversationSummary { double lastTimestamp = 0; @@ -32,12 +33,15 @@ public: bool saveMessage(LXMFMessage& msg); std::vector loadConversation(const std::string& peerHex) const; + std::vector loadConversationTail(const std::string& peerHex, size_t maxMessages) const; const std::vector& conversations() const { return _conversations; } void refreshConversations(); int messageCount(const std::string& peerHex) const; bool deleteConversation(const std::string& peerHex); std::vector loadPendingOutgoing() const; std::vector loadRecentMessageIds(size_t maxIds) const; + const std::vector& startupPendingOutgoing() const { return _startupPendingOutgoing; } + std::vector startupRecentMessageIds(size_t maxIds) const; void markConversationRead(const std::string& peerHex); bool updateMessageStatus(const std::string& peerHex, double timestamp, bool incoming, LXMFStatus newStatus); bool updateMessageStatusByCounter(const std::string& peerHex, uint32_t counter, bool incoming, LXMFStatus newStatus); @@ -56,7 +60,10 @@ private: void initReceiveCounter(); void buildSummaries(); void rebuildSummary(const std::string& peerHex); - ConversationSummary buildSummaryForPeer(const std::string& peerHex) const; + ConversationSummary buildSummaryForPeer( + const std::string& peerHex, + std::vector* pendingOut = nullptr, + std::vector>* recentIds = nullptr) const; void updateSummaryStatus(const std::string& peerHex, uint32_t counter, LXMFStatus oldStatus, LXMFStatus newStatus); void bumpRevision(); @@ -65,6 +72,8 @@ private: bool _externalStorageEnabled = false; std::vector _conversations; std::map _summaries; + std::vector _startupPendingOutgoing; + std::vector _startupRecentMessageIds; uint32_t _nextReceiveCounter = 0; uint32_t _revision = 0; }; diff --git a/src/storage/SDStore.cpp b/src/storage/SDStore.cpp index 38af9a8..60ba20d 100644 --- a/src/storage/SDStore.cpp +++ b/src/storage/SDStore.cpp @@ -1,5 +1,6 @@ #include "SDStore.h" #include "config/Config.h" +#include "util/PerfTrace.h" bool SDStore::begin(SPIClass* spi, int csPin) { if (!spi) return false; @@ -93,7 +94,11 @@ bool SDStore::readFile(const char* path, uint8_t* buffer, size_t maxLen, size_t& } bool SDStore::writeAtomic(const char* path, const uint8_t* data, size_t len) { - if (!_ready) return false; + unsigned long startMs = PerfTrace::nowMs(); + if (!_ready) { + PerfTrace::write("sd", "atomic", path, len, startMs, false); + return false; + } String tmpPath = String(path) + ".tmp"; String bakPath = String(path) + ".bak"; @@ -101,6 +106,7 @@ bool SDStore::writeAtomic(const char* path, const uint8_t* data, size_t len) { File f = SD.open(tmpPath.c_str(), FILE_WRITE); if (!f) { Serial.printf("[SD] writeAtomic: failed to open tmp %s\n", tmpPath.c_str()); + PerfTrace::write("sd", "atomic", path, len, startMs, false); return false; } size_t written = f.write(data, len); @@ -108,6 +114,7 @@ bool SDStore::writeAtomic(const char* path, const uint8_t* data, size_t len) { if (written != len) { Serial.printf("[SD] writeAtomic: write incomplete (%d/%d)\n", (int)written, (int)len); SD.remove(tmpPath.c_str()); + PerfTrace::write("sd", "atomic", path, len, startMs, false); return false; } @@ -116,6 +123,7 @@ bool SDStore::writeAtomic(const char* path, const uint8_t* data, size_t len) { Serial.println("[SD] writeAtomic: verify failed"); if (verify) verify.close(); SD.remove(tmpPath.c_str()); + PerfTrace::write("sd", "atomic", path, len, startMs, false); return false; } verify.close(); @@ -132,26 +140,35 @@ bool SDStore::writeAtomic(const char* path, const uint8_t* data, size_t len) { if (!SD.rename(tmpPath.c_str(), path)) { Serial.printf("[SD] writeAtomic: rename failed %s -> %s\n", tmpPath.c_str(), path); if (SD.exists(bakPath.c_str())) { SD.rename(bakPath.c_str(), path); } + PerfTrace::write("sd", "atomic", path, len, startMs, false); return false; } SD.remove(bakPath.c_str()); + PerfTrace::write("sd", "atomic", path, len, startMs, true); return true; } bool SDStore::writeSimple(const char* path, const uint8_t* data, size_t len) { - if (!_ready) return false; + unsigned long startMs = PerfTrace::nowMs(); + if (!_ready) { + PerfTrace::write("sd", "simple", path, len, startMs, false); + return false; + } File f = SD.open(path, FILE_WRITE); if (!f) { Serial.printf("[SD] writeSimple: failed to open %s\n", path); + PerfTrace::write("sd", "simple", path, len, startMs, false); return false; } size_t written = f.write(data, len); f.close(); if (written != len) { Serial.printf("[SD] writeSimple: write incomplete (%d/%d)\n", (int)written, (int)len); + PerfTrace::write("sd", "simple", path, len, startMs, false); return false; } + PerfTrace::write("sd", "simple", path, len, startMs, true); return true; } diff --git a/src/ui/UIManager.cpp b/src/ui/UIManager.cpp index 163aba3..978a707 100644 --- a/src/ui/UIManager.cpp +++ b/src/ui/UIManager.cpp @@ -2,6 +2,7 @@ #include "Theme.h" #include "LvTheme.h" #include "LvInput.h" +#include "util/PerfTrace.h" // --- LvScreen base --- @@ -42,27 +43,55 @@ void UIManager::begin() { void UIManager::setScreen(LvScreen* screen) { if (_currentLvScreen == screen) return; + const char* fromTitle = _currentLvScreen ? _currentLvScreen->title() : "none"; + const char* toTitle = screen ? screen->title() : "none"; + unsigned long startMs = PerfTrace::nowMs(); + unsigned long exitMs = 0; + unsigned long destroyMs = 0; + unsigned long showMs = 0; + unsigned long cleanMs = 0; + unsigned long createMs = 0; + unsigned long enterMs = 0; // Transition from previous LVGL screen if (_currentLvScreen) { + unsigned long phaseMs = millis(); _currentLvScreen->onExit(); + exitMs = millis() - phaseMs; + phaseMs = millis(); _currentLvScreen->destroyUI(); + destroyMs = millis() - phaseMs; } _currentLvScreen = screen; // Show LVGL layers + unsigned long phaseMs = millis(); if (!_bootMode) { lv_obj_clear_flag(_lvStatusBar.obj(), LV_OBJ_FLAG_HIDDEN); lv_obj_clear_flag(_lvTabBar.obj(), LV_OBJ_FLAG_HIDDEN); } lv_obj_clear_flag(_lvContent, LV_OBJ_FLAG_HIDDEN); + showMs = millis() - phaseMs; if (_currentLvScreen) { // Clean content area + phaseMs = millis(); lv_obj_clean(_lvContent); + cleanMs = millis() - phaseMs; + phaseMs = millis(); _currentLvScreen->createUI(_lvContent); + createMs = millis() - phaseMs; + phaseMs = millis(); _currentLvScreen->onEnter(); + enterMs = millis() - phaseMs; + } + + unsigned long elapsed = millis() - startMs; + if (PerfTrace::shouldLog(elapsed, RSDECK_PERF_UI_TRACE_MS)) { + Serial.printf("[PERF] UI transition: %s -> %s total=%lums exit=%lums destroy=%lums show=%lums clean=%lums create=%lums enter=%lums boot=%s\n", + fromTitle, toTitle, elapsed, exitMs, destroyMs, showMs, + cleanMs, createMs, enterMs, _bootMode ? "yes" : "no"); } } diff --git a/src/ui/screens/LvMessageView.cpp b/src/ui/screens/LvMessageView.cpp index 622d393..89becc4 100644 --- a/src/ui/screens/LvMessageView.cpp +++ b/src/ui/screens/LvMessageView.cpp @@ -4,6 +4,7 @@ #include "ui/LvTabBar.h" #include "reticulum/LXMFManager.h" #include "reticulum/AnnounceManager.h" +#include "util/PerfTrace.h" #include #include #include @@ -109,6 +110,22 @@ void LvMessageView::updateHeader() { } } +void LvMessageView::markVisibleConversationRead() { + if (!_markReadPending || !_lxmf) return; + + unsigned long startMs = PerfTrace::nowMs(); + _lxmf->markRead(_peerHex); + _markReadPending = false; + if (_ui) { + _ui->lvTabBar().setUnreadCount(LvTabBar::TAB_MSGS, _lxmf->unreadCount()); + } + unsigned long elapsed = PerfTrace::elapsedMs(startMs); + if (PerfTrace::shouldLog(elapsed, RSDECK_PERF_MSG_TRACE_MS)) { + Serial.printf("[PERF] Chat markRead: peer=%s total=%lums\n", + _peerHex.substr(0, 8).c_str(), elapsed); + } +} + void LvMessageView::updateComposerState() { if (!_btnSend) return; bool hasText = !_inputText.empty(); @@ -298,12 +315,18 @@ void LvMessageView::destroyUI() { } void LvMessageView::onEnter() { + unsigned long startMs = PerfTrace::nowMs(); + unsigned long markReadMs = 0; + unsigned long tabBadgeMs = 0; + unsigned long callbackMs = 0; + unsigned long resetMs = 0; + unsigned long headerMs = 0; + unsigned long rebuildMs = 0; if (_lxmf) { - _lxmf->markRead(_peerHex); - // Update unread badge on Messages tab - if (_ui) _ui->lvTabBar().setUnreadCount(LvTabBar::TAB_MSGS, _lxmf->unreadCount()); + _markReadPending = true; // Register status callback - partial update without full rebuild std::string peer = _peerHex; + unsigned long phaseMs = millis(); _lxmf->setStatusCallback([this, peer](const std::string& peerHex, double ts, uint32_t savedCounter, LXMFStatus newStatus) { if (peerHex != peer) return; for (int i = (int)_cachedMsgs.size() - 1; i >= 0; i--) { @@ -317,8 +340,11 @@ void LvMessageView::onEnter() { } } }); + callbackMs = millis() - phaseMs; } + unsigned long phaseMs = millis(); _lastMsgCount = -1; + _knownTotalCount = -1; _lastRefreshMs = 0; _inputText.clear(); hideSendModeMenu(); @@ -326,14 +352,27 @@ void LvMessageView::onEnter() { if (_textarea) { updateComposerText(); } + resetMs = millis() - phaseMs; + phaseMs = millis(); updateHeader(); updateComposerState(); + headerMs = millis() - phaseMs; _cachedMsgs.clear(); // Force fresh load + phaseMs = millis(); rebuildMessages(); + rebuildMs = millis() - phaseMs; + + unsigned long elapsed = millis() - startMs; + if (PerfTrace::shouldLog(elapsed, RSDECK_PERF_UI_TRACE_MS)) { + Serial.printf("[PERF] Chat onEnter: peer=%s msgs=%d total=%lums markRead=%lums tab=%lums callback=%lums reset=%lums header=%lums rebuild=%lums\n", + _peerHex.substr(0, 8).c_str(), (int)_cachedMsgs.size(), elapsed, + markReadMs, tabBadgeMs, callbackMs, resetMs, headerMs, rebuildMs); + } } void LvMessageView::onExit() { if (_lxmf) _lxmf->setStatusCallback(nullptr); + _markReadPending = false; hideSendModeMenu(); _inputText.clear(); _cachedMsgs.clear(); @@ -345,17 +384,23 @@ void LvMessageView::onExit() { void LvMessageView::refreshUI() { if (!_lxmf) return; unsigned long now = millis(); + markVisibleConversationRead(); if (now - _lastRefreshMs < REFRESH_INTERVAL_MS) return; _lastRefreshMs = now; updateHeader(); // Only reload from disk when message count changes (new messages arrive) auto* summary = _lxmf->getConversationSummary(_peerHex); - if (summary && summary->totalCount == (int)_cachedMsgs.size()) return; + int totalCount = summary ? summary->totalCount : -1; + if (summary && totalCount == _knownTotalCount) return; - auto newMsgs = _lxmf->getMessages(_peerHex); - if (newMsgs.size() != _cachedMsgs.size()) { - if (newMsgs.size() > _cachedMsgs.size()) { + auto newMsgs = _lxmf->getRecentMessages(_peerHex, CHAT_VIEW_MAX_MESSAGES); + int newKnownTotal = summary ? totalCount : (int)newMsgs.size(); + if (newKnownTotal != _knownTotalCount || newMsgs.size() != _cachedMsgs.size()) { + bool canAppend = !_cachedMsgs.empty() && + _cachedMsgs.size() < CHAT_VIEW_MAX_MESSAGES && + newMsgs.size() > _cachedMsgs.size(); + if (canAppend) { // Incremental append - only create widgets for new messages size_t oldCount = _cachedMsgs.size(); _cachedMsgs = std::move(newMsgs); @@ -370,14 +415,15 @@ void LvMessageView::refreshUI() { } lv_obj_scroll_to_y(_msgScroll, LV_COORD_MAX, LV_ANIM_OFF); } else { - // Count decreased (deletion?) - full rebuild + // Tail window shifted, count decreased, or cache was empty - full visible-window rebuild. _cachedMsgs = std::move(newMsgs); _lastMsgCount = (int)_cachedMsgs.size(); rebuildMessages(); } + _knownTotalCount = newKnownTotal; // Mark as read since user is actively viewing this conversation - _lxmf->markRead(_peerHex); - if (_ui) _ui->lvTabBar().setUnreadCount(LvTabBar::TAB_MSGS, _lxmf->unreadCount()); + _markReadPending = true; + markVisibleConversationRead(); } } @@ -486,19 +532,35 @@ void LvMessageView::appendMessage(const LXMFMessage& msg) { void LvMessageView::rebuildMessages() { if (!_lxmf || !_msgScroll) return; unsigned long startMs = millis(); + unsigned long loadMs = 0; + unsigned long cleanMs = 0; + unsigned long emptyMs = 0; + unsigned long appendMs = 0; + unsigned long scrollMs = 0; + bool loadedFromStore = false; // Only load from disk if _cachedMsgs is empty (first call or after send) if (_cachedMsgs.empty()) { - _cachedMsgs = _lxmf->getMessages(_peerHex); + unsigned long phaseMs = millis(); + _cachedMsgs = _lxmf->getRecentMessages(_peerHex, CHAT_VIEW_MAX_MESSAGES); + loadMs = millis() - phaseMs; + loadedFromStore = true; + } + if (_lxmf) { + auto* summary = _lxmf->getConversationSummary(_peerHex); + _knownTotalCount = summary ? summary->totalCount : (int)_cachedMsgs.size(); } _lastMsgCount = (int)_cachedMsgs.size(); _lastRefreshMs = millis(); + unsigned long phaseMs = millis(); lv_obj_clean(_msgScroll); + cleanMs = millis() - phaseMs; _statusLabels.clear(); _textLabels.clear(); _bubbleBoxes.clear(); if (_cachedMsgs.empty()) { + phaseMs = millis(); lv_obj_set_layout(_msgScroll, 0); lv_obj_t* empty = lv_obj_create(_msgScroll); @@ -529,23 +591,36 @@ void LvMessageView::rebuildMessages() { lv_obj_set_style_text_color(sub, lv_color_hex(Theme::TEXT_SECONDARY), 0); lv_label_set_text(sub, "Thread is quiet"); lv_obj_align(sub, LV_ALIGN_TOP_MID, 0, 54); + emptyMs = millis() - phaseMs; + unsigned long elapsed = millis() - startMs; + if (PerfTrace::shouldLog(elapsed, RSDECK_PERF_UI_TRACE_MS)) { + Serial.printf("[PERF] Chat rebuild: peer=%s msgs=0 loaded=%s load=%lums clean=%lums empty=%lums append=0ms scroll=0ms total=%lums\n", + _peerHex.substr(0, 8).c_str(), loadedFromStore ? "yes" : "no", + loadMs, cleanMs, emptyMs, elapsed); + } return; } + phaseMs = millis(); lv_obj_set_layout(_msgScroll, LV_LAYOUT_FLEX); lv_obj_set_flex_flow(_msgScroll, LV_FLEX_FLOW_COLUMN); for (const auto& msg : _cachedMsgs) { appendMessage(msg); } + appendMs = millis() - phaseMs; // Auto-scroll to bottom + phaseMs = millis(); lv_obj_scroll_to_y(_msgScroll, LV_COORD_MAX, LV_ANIM_OFF); + scrollMs = millis() - phaseMs; unsigned long elapsed = millis() - startMs; - if (elapsed > 40) { - Serial.printf("[PERF] Chat rebuild: %d msgs in %lums\n", - (int)_cachedMsgs.size(), (unsigned long)elapsed); + if (PerfTrace::shouldLog(elapsed, RSDECK_PERF_UI_TRACE_MS)) { + Serial.printf("[PERF] Chat rebuild: peer=%s msgs=%d loaded=%s load=%lums clean=%lums empty=0ms append=%lums scroll=%lums total=%lums\n", + _peerHex.substr(0, 8).c_str(), (int)_cachedMsgs.size(), + loadedFromStore ? "yes" : "no", loadMs, cleanMs, + appendMs, scrollMs, elapsed); } } @@ -608,27 +683,56 @@ void LvMessageView::applyStatusGlyph(lv_obj_t* lbl, LXMFStatus status) { } void LvMessageView::sendCurrentMessage(bool viaLink) { + unsigned long startMs = PerfTrace::nowMs(); if (!_lxmf || _peerHex.empty() || _inputText.empty()) return; + size_t inputBytes = _inputText.size(); if (_inputText.size() > MAX_COMPOSER_CHARS) { +#if RSDECK_PERF_TRACE + Serial.printf("[PERF] Chat send: peer=%s bytes=%u link=%s queued=no reason=too_long total=%lums\n", + _peerHex.substr(0, 8).c_str(), (unsigned)inputBytes, + viaLink ? "yes" : "no", PerfTrace::elapsedMs(startMs)); +#endif if (_ui) _ui->lvStatusBar().showToast("Message too long", 1500); return; } + unsigned long hashMs = millis(); RNS::Bytes destHash; destHash.assignHex(_peerHex.c_str()); + hashMs = millis() - hashMs; + unsigned long queueStartMs = millis(); bool queued = viaLink ? _lxmf->sendMessageViaLink(destHash, _inputText.c_str()) : _lxmf->sendMessage(destHash, _inputText.c_str()); + unsigned long queueMs = millis() - queueStartMs; if (!queued) { +#if RSDECK_PERF_TRACE + Serial.printf("[PERF] Chat send: peer=%s bytes=%u link=%s queued=no reason=queue_full hash=%lums queue=%lums total=%lums\n", + _peerHex.substr(0, 8).c_str(), (unsigned)inputBytes, + viaLink ? "yes" : "no", hashMs, queueMs, + PerfTrace::elapsedMs(startMs)); +#endif if (_ui) _ui->lvStatusBar().showToast("Message queue full", 1500); return; } if (viaLink && _ui) _ui->lvStatusBar().showToast("Link send queued", 1200); + unsigned long composerStartMs = millis(); _inputText.clear(); updateComposerState(); _cachedMsgs.clear(); // Force fresh load in rebuildMessages + _knownTotalCount = -1; + unsigned long composerMs = millis() - composerStartMs; + unsigned long rebuildStartMs = millis(); rebuildMessages(); + unsigned long rebuildMs = millis() - rebuildStartMs; + unsigned long elapsed = millis() - startMs; +#if RSDECK_PERF_TRACE + Serial.printf("[PERF] Chat send: peer=%s bytes=%u link=%s queued=yes hash=%lums queue=%lums composer=%lums rebuild=%lums msgs=%d total=%lums\n", + _peerHex.substr(0, 8).c_str(), (unsigned)inputBytes, + viaLink ? "yes" : "no", hashMs, queueMs, composerMs, + rebuildMs, (int)_cachedMsgs.size(), elapsed); +#endif } bool LvMessageView::handleKey(const KeyEvent& event) { @@ -697,8 +801,14 @@ bool LvMessageView::handleKey(const KeyEvent& event) { if (_ui) _ui->lvStatusBar().showToast("Message too long", 900); return true; } + unsigned long inputStartMs = millis(); _inputText += (char)event.character; updateComposerState(); + unsigned long elapsed = millis() - inputStartMs; + if (PerfTrace::shouldLog(elapsed, RSDECK_PERF_UI_TRACE_MS)) { + Serial.printf("[PERF] Chat input: peer=%s chars=%u total=%lums\n", + _peerHex.substr(0, 8).c_str(), (unsigned)_inputText.size(), elapsed); + } return true; } diff --git a/src/ui/screens/LvMessageView.h b/src/ui/screens/LvMessageView.h index dcbc574..1abb029 100644 --- a/src/ui/screens/LvMessageView.h +++ b/src/ui/screens/LvMessageView.h @@ -35,6 +35,7 @@ private: void appendMessage(const LXMFMessage& msg); std::string getPeerName(); void updateHeader(); + void markVisibleConversationRead(); void updateComposerState(); void refreshComposerPlaceholder(); void updateComposerText(); @@ -50,8 +51,10 @@ private: std::string _peerHex; std::string _inputText; int _lastMsgCount = -1; + int _knownTotalCount = -1; unsigned long _lastRefreshMs = 0; std::vector _cachedMsgs; + bool _markReadPending = false; void updateMessageStatus(int msgIdx, LXMFStatus status); static void applyStatusGlyph(lv_obj_t* lbl, LXMFStatus status); @@ -77,5 +80,6 @@ private: std::vector _bubbleBoxes; static constexpr unsigned long REFRESH_INTERVAL_MS = 2000; // Check for new messages every 2s + static constexpr size_t CHAT_VIEW_MAX_MESSAGES = 40; static constexpr size_t MAX_COMPOSER_CHARS = 120; }; diff --git a/src/ui/screens/LvSettingsScreen.cpp b/src/ui/screens/LvSettingsScreen.cpp index 7954998..17bbe1e 100644 --- a/src/ui/screens/LvSettingsScreen.cpp +++ b/src/ui/screens/LvSettingsScreen.cpp @@ -179,8 +179,8 @@ bool LvSettingsScreen::settingNeedsReboot(const SettingItem& item) const { if (labelEq(item.label, "WiFi Profile")) return s.wifiSTASelected != _rebootSnap.wifiSTASelected; if (isWiFiSSIDLabel(item.label) || isWiFiPasswordLabel(item.label)) return interfaceSettingsChanged(); if (labelEq(item.label, "Scan Networks") || labelEq(item.label, "Forget Network")) return interfaceSettingsChanged(); - if (labelEq(item.label, "TCP Relay") || labelEq(item.label, "Relay Host") || - labelEq(item.label, "Relay Port")) return tcpSettingsChanged(); + if (labelEq(item.label, "TCP Server") || labelEq(item.label, "Host") || + labelEq(item.label, "Port")) return tcpSettingsChanged(); if (labelEq(item.label, "LAN Discovery")) return s.autoIfaceEnabled != _rebootSnap.autoIfaceEnabled; if (labelEq(item.label, "SD Message Store")) return storageSettingsChanged(); return false; @@ -807,7 +807,7 @@ void LvSettingsScreen::buildItems() { } { SettingItem tcpPreset; - tcpPreset.label = "TCP Relay"; + tcpPreset.label = "TCP Server"; tcpPreset.type = SettingType::ENUM_CHOICE; tcpPreset.getter = [&s]() { for (auto& ep : s.tcpConnections) { @@ -837,7 +837,7 @@ void LvSettingsScreen::buildItems() { } { SettingItem tcpHost; - tcpHost.label = "Relay Host"; + tcpHost.label = "Host"; tcpHost.type = SettingType::TEXT_INPUT; tcpHost.textGetter = [&s]() { return s.tcpConnections.empty() ? String("") : s.tcpConnections[0].host; }; tcpHost.textSetter = [&s](const String& v) { @@ -850,7 +850,7 @@ void LvSettingsScreen::buildItems() { _items.push_back(tcpHost); idx++; } - _items.push_back({"Relay Port", SettingType::INTEGER, + _items.push_back({"Port", SettingType::INTEGER, [&s]() { return s.tcpConnections.empty() ? TCP_DEFAULT_PORT : (int)s.tcpConnections[0].port; }, [&s](int v) { if (s.tcpConnections.empty()) { @@ -2138,7 +2138,7 @@ void LvSettingsScreen::applyAndSave() { else if (_sd && _flash) { saved = _cfg->save(*_sd, *_flash); } else if (_flash) { saved = _cfg->save(*_flash); } - // TCP relay changes are persisted only. Recreating clients live can race + // TCP server changes are persisted only. Recreating clients live can race // in-flight sockets/netif teardown on ESP32; reboot applies them cleanly. // Apply GPS toggle live (start/stop GPS UART) @@ -2156,12 +2156,12 @@ void LvSettingsScreen::applyAndSave() { _ui->lvStatusBar().showToast("Save failed", 2000); } else if (_rebootNeeded && !wasRebootNeeded) { _ui->lvStatusBar().showToast( - tcpChanged ? "TCP relay saved; reboot to apply" : "Interface changes saved; reboot to apply", + tcpChanged ? "TCP server saved; reboot to apply" : "Interface changes saved; reboot to apply", 3000); } else if (!_rebootNeeded && wasRebootNeeded) { _ui->lvStatusBar().showToast("Pending reboot cleared", 1500); } else if (tcpChanged) { - _ui->lvStatusBar().showToast("TCP relay saved; reboot to apply", 3000); + _ui->lvStatusBar().showToast("TCP server saved; reboot to apply", 3000); } else { _ui->lvStatusBar().showToast("Saved", 800); } diff --git a/src/util/PerfTrace.h b/src/util/PerfTrace.h new file mode 100644 index 0000000..25aa2f9 --- /dev/null +++ b/src/util/PerfTrace.h @@ -0,0 +1,70 @@ +#pragma once + +#include + +#ifndef RSDECK_PERF_TRACE +#define RSDECK_PERF_TRACE 1 +#endif + +#ifndef RSDECK_PERF_WRITE_TRACE_MS +#define RSDECK_PERF_WRITE_TRACE_MS 20UL +#endif + +#ifndef RSDECK_PERF_MSG_TRACE_MS +#define RSDECK_PERF_MSG_TRACE_MS 25UL +#endif + +#ifndef RSDECK_PERF_UI_TRACE_MS +#define RSDECK_PERF_UI_TRACE_MS 16UL +#endif + +#ifndef RSDECK_PERF_PERSIST_TRACE_MS +#define RSDECK_PERF_PERSIST_TRACE_MS 25UL +#endif + +namespace PerfTrace { + +inline unsigned long nowMs() { + return millis(); +} + +inline unsigned long elapsedMs(unsigned long startMs) { + return millis() - startMs; +} + +inline bool shouldLog(unsigned long durationMs, unsigned long thresholdMs) { +#if RSDECK_PERF_TRACE + return durationMs >= thresholdMs; +#else + (void)durationMs; + (void)thresholdMs; + return false; +#endif +} + +inline void write(const char* backend, const char* op, const char* path, + size_t bytes, unsigned long startMs, bool ok, + unsigned long thresholdMs = RSDECK_PERF_WRITE_TRACE_MS) { +#if RSDECK_PERF_TRACE + const unsigned long durationMs = elapsedMs(startMs); + if (!ok || durationMs >= thresholdMs) { + Serial.printf("[PERF] WRITE backend=%s op=%s path=%s bytes=%u ok=%s in %lums\n", + backend ? backend : "?", + op ? op : "?", + path ? path : "?", + (unsigned)bytes, + ok ? "yes" : "no", + durationMs); + } +#else + (void)backend; + (void)op; + (void)path; + (void)bytes; + (void)startMs; + (void)ok; + (void)thresholdMs; +#endif +} + +} // namespace PerfTrace