попытки запустится до 1 МГц

.gitignore

@@ -0,0 +1 @@
+/tests/

OpticalChannelTester/App.cpp

@@ -1,31 +1,52 @@
 #include "App.h"
 #include "Config.h"
+#include "Log.h"
 #include <WiFi.h>
 #include <esp_mac.h>
 #include <esp_system.h>
 #include <string.h>
 
+namespace {
+const char *appStateName(AppState state) {
+  static const char *names[] = {"IDLE", "MENU", "SOLO_MEASURE", "MASTER_DISCOVER",
+    "MASTER_WAIT_READY", "MASTER_WAIT_RESULT", "SLAVE_READY", "SLAVE_WAIT_START",
+    "SLAVE_MEASURE", "SLAVE_WAIT_ACK", "FINISHED"};
+  const uint8_t index = static_cast<uint8_t>(state);
+  return index < sizeof(names) / sizeof(names[0]) ? names[index] : "UNKNOWN";
+}
+
+const char *buttonEventName(ButtonEvent event) {
+  static const char *names[] = {"NONE", "SHORT", "LONG", "REPEAT"};
+  const uint8_t index = static_cast<uint8_t>(event);
+  return index < sizeof(names) / sizeof(names[0]) ? names[index] : "UNKNOWN";
+}
+}
+
 App::App() : startButton_(GPIO_BUTTON_START), modeButton_(GPIO_BUTTON_MODE), measurement_(receiver_) {}
 
 void App::begin() {
   Serial.begin(SERIAL_BAUD);
+  Log::printf("BOOT", "firmware start, Serial=%lu baud", SERIAL_BAUD);
   startButton_.begin(); modeButton_.begin(); pwm_.begin();
   bootCheckStartedMs_ = millis();
   bootResetCandidate_ = startButton_.pressed() && modeButton_.pressed();
+  Log::printf("BOOT", "buttons initialized, factory-reset candidate=%s", bootResetCandidate_ ? "YES" : "NO");
   if (!bootResetCandidate_) finishInitialization(false);
 }
 
 void App::finishInitialization(bool factoryReset) {
   if (initialized_) return;
+  Log::printf("BOOT", "initialization continues, factory-reset=%s", factoryReset ? "YES" : "NO");
   if (factoryReset) {
-    store_.defaults(settings_); store_.save(settings_); Serial.println("FACTORY DEFAULTS RESTORED");
+    store_.defaults(settings_); store_.save(settings_); Log::event("BOOT", "FACTORY DEFAULTS RESTORED");
   } else if (!store_.load(settings_)) {
-    store_.save(settings_); Serial.println("NVS invalid/missing: defaults loaded");
+    store_.save(settings_); Log::event("BOOT", "NVS invalid/missing: defaults loaded");
   }
   params_ = store_.params(settings_);
-  if (!display_.begin()) Serial.println("OLED unavailable; continuing through Serial");
+  if (!display_.begin()) Log::event("BOOT", "OLED unavailable; Serial UI remains fully operational");
   initialized_ = true;
-  if (!receiver_.begin()) { Serial.println("FATAL: capture peripheral init failed"); finish(false, FailReason::UNSUPPORTED); return; }
+  if (!receiver_.begin()) { Log::event("BOOT", "FATAL: capture peripheral init failed"); finish(false, FailReason::UNSUPPORTED); return; }
+  Log::printf("BOOT", "capture initialized: %s", receiver_.highRateBackend() ? "RMT DMA" : "RMT ping-pong");
   printConfiguration(); showIdle();
 }
 
@@ -33,6 +54,10 @@ void App::update() {
   const uint32_t now = millis();
   const ButtonEvent startEvent = startButton_.update(now);
   const ButtonEvent modeEvent = modeButton_.update(now);
+  if (startEvent != ButtonEvent::NONE)
+    Log::printf("INPUT", "START %s state=%s", buttonEventName(startEvent), appStateName(state_));
+  if (modeEvent != ButtonEvent::NONE)
+    Log::printf("INPUT", "MODE %s state=%s", buttonEventName(modeEvent), appStateName(state_));
   if (!initialized_) {
     if (!startButton_.pressed() || !modeButton_.pressed()) finishInitialization(false);
     else if (now - bootCheckStartedMs_ >= FACTORY_RESET_HOLD_MS) finishInitialization(true);
@@ -40,20 +65,26 @@ void App::update() {
   }
   if (state_ != AppState::IDLE && state_ != AppState::MENU && state_ != AppState::FINISHED &&
       startEvent == ButtonEvent::LONG) { abortTest(); return; }
+  if (state_ != AppState::IDLE && state_ != AppState::MENU && state_ != AppState::FINISHED &&
+      modeEvent != ButtonEvent::NONE) Log::event("ACTION", "MODE ignored while test is active");
 
   if (state_ == AppState::IDLE || state_ == AppState::FINISHED) {
     if (modeEvent == ButtonEvent::SHORT) {
-      settings_.role = (settings_.role + 1U) % 3U; store_.save(settings_); params_ = store_.params(settings_); showIdle();
-      Serial.printf("MODE: %s\n", roleName(static_cast<Role>(settings_.role)));
+      settings_.role = (settings_.role + 1U) % 3U; const bool saved = store_.save(settings_);
+      params_ = store_.params(settings_); showIdle();
+      Log::printf("ACTION", "role changed to %s, NVS=%s", roleName(static_cast<Role>(settings_.role)), saved ? "OK" : "FAILED");
     } else if (modeEvent == ButtonEvent::LONG) {
-      state_ = AppState::MENU; menuItem_ = 0; showMenu();
-    } else if (startEvent == ButtonEvent::SHORT) startTest();
+      state_ = AppState::MENU; menuItem_ = 0; Log::event("ACTION", "settings menu entered"); showMenu();
+    } else if (startEvent == ButtonEvent::SHORT) { Log::event("ACTION", "test start requested"); startTest(); }
     return;
   }
   if (state_ == AppState::MENU) {
-    if (modeEvent == ButtonEvent::SHORT) { menuItem_ = (menuItem_ + 1U) % 7U; showMenu(); }
+    if (modeEvent == ButtonEvent::SHORT) {
+      menuItem_ = (menuItem_ + 1U) % 7U; Log::printf("ACTION", "menu item selected index=%u", menuItem_); showMenu();
+    }
     else if (modeEvent == ButtonEvent::LONG) {
-      sanitizeRange(); store_.save(settings_); params_ = store_.params(settings_);
+      sanitizeRange(); const bool saved = store_.save(settings_); params_ = store_.params(settings_);
+      Log::printf("ACTION", "settings menu saved and closed, NVS=%s", saved ? "OK" : "FAILED");
       state_ = AppState::IDLE; printConfiguration(); showIdle();
     } else if (startEvent == ButtonEvent::SHORT) changeMenu(+1);
     else if (startEvent == ButtonEvent::LONG || startEvent == ButtonEvent::REPEAT) changeMenu(-1);
@@ -62,7 +93,13 @@ void App::update() {
   if (state_ == AppState::SOLO_MEASURE) {
     const MeasureState ms = measurement_.update();
     if (ms == MeasureState::FAIL) { printStageStats(measurement_.stats(), requestedHz_); finish(false, measurement_.reason()); }
-    else if (ms == MeasureState::PASS) { printStageStats(measurement_.stats(), requestedHz_); stagePassed(); }
+    else if (ms == MeasureState::PASS) {
+      printStageStats(measurement_.stats(), requestedHz_);
+      if (measurement_.reason() == FailReason::DATA_LOST) {
+        sweepHadDataLoss_ = true; if (!firstDataLossHz_) firstDataLossHz_ = requestedHz_;
+      }
+      stagePassed();
+    }
   } else if (state_ == AppState::MASTER_DISCOVER || state_ == AppState::MASTER_WAIT_READY ||
              state_ == AppState::MASTER_WAIT_RESULT) {
     handleRadio(); updateMaster();
@@ -97,7 +134,9 @@ void App::changeMenu(int d) {
     case 5: value = &settings_.repeatIndex; count = countOf(REPEAT_OPTIONS); break;
     default: value = &settings_.dutyIndex; count = countOf(DUTY_OPTIONS_PCT); break;
   }
-  *value = static_cast<uint8_t>((*value + count + d) % count); sanitizeRange(); params_ = store_.params(settings_); showMenu();
+  *value = static_cast<uint8_t>((*value + count + d) % count);
+  Log::printf("ACTION", "menu item=%u changed direction=%+d new-index=%u", menuItem_, d, *value);
+  sanitizeRange(); params_ = store_.params(settings_); showMenu();
 }
 
 void App::showMenu() {
@@ -117,8 +156,13 @@ void App::showMenu() {
 
 void App::startTest() {
   params_ = store_.params(settings_); stageCount_ = frequencyPointCount(params_.startHz, params_.endHz, params_.stepHz);
-  stageIndex_ = 0; pendingReason_ = FailReason::NONE;
+  stageIndex_ = 0; pendingReason_ = FailReason::NONE; sweepHadDataLoss_ = false; firstDataLossHz_ = 0;
   if (!stageCount_) { finish(false, FailReason::UNSUPPORTED); return; }
+  Log::printf("TEST", "starting role=%s stages=%lu", roleName(static_cast<Role>(settings_.role)), stageCount_);
+  if (SERIAL_MINIMAL_LOG)
+    Log::printf("CONFIG", "mode=%s range=%lu..%luHz step=%luHz accuracy=%.2f%% time=%lums repeats=%u duty=%u%% stages=%lu",
+      roleName(static_cast<Role>(settings_.role)), params_.startHz, params_.endHz, params_.stepHz,
+      params_.accuracyPct, params_.testTimeMs, params_.repeats, params_.dutyPct, stageCount_);
   printConfiguration();
   const Role role = static_cast<Role>(settings_.role);
   if (role == Role::SOLO) {
@@ -126,7 +170,7 @@ void App::startTest() {
     state_ = AppState::SOLO_MEASURE;
   } else if (!radio_.begin()) finish(false, FailReason::LINK_LOST);
   else if (role == Role::MASTER) startMasterDiscovery();
-  else { state_ = AppState::SLAVE_READY; display_.show("SLAVE READY", "WAIT MASTER"); Serial.println("SLAVE READY"); }
+  else { state_ = AppState::SLAVE_READY; Log::event("TEST", "Slave armed and waiting for Master"); display_.show("SLAVE READY", "WAIT MASTER"); }
 }
 
 bool App::prepareStage() {
@@ -134,11 +178,20 @@ bool App::prepareStage() {
   const uint32_t maxHz = TARGET_IS_C3 ? C3_STRICT_MAX_HZ :
     (receiver_.highRateBackend() ? S3_STRICT_MAX_HZ : C3_STRICT_MAX_HZ);
   if (requestedHz_ > maxHz) { finish(false, FailReason::UNSUPPORTED); return false; }
-  if (!pwm_.start(requestedHz_, params_.dutyPct, actual_)) { finish(false, FailReason::RESOLUTION); return false; }
+  Log::printf("PWM", "starting GPIO=%u requested=%luHz duty=%u%%", GPIO_PWM, requestedHz_, params_.dutyPct);
+  if (!pwm_.start(requestedHz_, params_.dutyPct, actual_)) {
+    Log::printf("PWM", "START FAILED GPIO=%u requested=%luHz; LEDC attach/write/read failed",
+      GPIO_PWM, requestedHz_);
+    finish(false, FailReason::RESOLUTION); return false;
+  }
   const FailReason resolution = validateResolution(actual_.actualHz, actual_.actualDutyPct, params_.accuracyPct,
                                                    receiver_.tickHz(), actual_.bits);
-  if (resolution != FailReason::NONE) { finish(false, resolution); return false; }
-  Serial.printf("STAGE %lu/%lu requested=%luHz actual=%luHz duty=%.2f%% bits=%u\n",
+  if (resolution != FailReason::NONE) {
+    Log::printf("PWM", "resolution rejected: actual=%luHz duty=%.3f%% bits=%u RXclock=%luHz tolerance=%.3f%%",
+      actual_.actualHz, actual_.actualDutyPct, actual_.bits, receiver_.tickHz(), params_.accuracyPct);
+    finish(false, resolution); return false;
+  }
+  Log::printf("PWM", "stage=%lu/%lu requested=%luHz actual=%luHz duty=%.2f%% bits=%u STARTED",
     stageIndex_ + 1, stageCount_, requestedHz_, actual_.actualHz, actual_.actualDutyPct, actual_.bits);
   char f[12], one[24], two[24]; Display::formatFrequency(actual_.actualHz, f, sizeof(f));
   snprintf(one, sizeof(one), "F %s D %.1f%%", f, actual_.actualDutyPct);
@@ -150,12 +203,22 @@ bool App::prepareStage() {
 }
 
 bool App::startLocalMeasurement(float hz, float duty) {
-  return measurement_.start(hz, duty, params_.accuracyPct, params_.testTimeMs, params_.repeats, PWM_SETTLE_CYCLES);
+  Log::printf("MEASURE", "arming expected=%.3fHz duty=%.3f%% tolerance=%.3f%% settle=%u cycles window=%lums x%u; per-pulse logging suspended",
+    hz, duty, params_.accuracyPct, PWM_SETTLE_CYCLES, params_.testTimeMs, params_.repeats);
+  const bool ok = measurement_.start(hz, duty, params_.accuracyPct, params_.testTimeMs, params_.repeats, PWM_SETTLE_CYCLES);
+  Log::printf("MEASURE", "receiver start %s, RMT chunk=%u symbols", ok ? "OK" : "FAILED",
+    receiver_.receiveChunkSymbols());
+  return ok;
 }
 
 void App::stagePassed() {
+  Log::printf("TEST", "stage %lu/%lu PASS; PWM stopping", stageIndex_ + 1, stageCount_);
   pwm_.stop();
-  if (++stageIndex_ >= stageCount_) { finish(true, FailReason::NONE); return; }
+  if (++stageIndex_ >= stageCount_) {
+    if (sweepHadDataLoss_) { requestedHz_ = firstDataLossHz_; finish(false, FailReason::DATA_LOST); }
+    else finish(true, FailReason::NONE);
+    return;
+  }
   if (static_cast<Role>(settings_.role) == Role::SOLO) { if (prepareStage()) state_ = AppState::SOLO_MEASURE; }
   else if (static_cast<Role>(settings_.role) == Role::MASTER) {
     requestedHz_ = frequencyAt(params_.startHz, params_.endHz, params_.stepHz, stageIndex_);
@@ -168,7 +231,8 @@ void App::startMasterDiscovery() {
   session_ = esp_random(); if (!session_) session_ = 1; sequence_ = 1; havePeer_ = false; radio_.flush();
   pendingPacket_ = makePacket(MessageType::DISCOVER); radio_.sendBroadcast(pendingPacket_);
   lastSendMs_ = millis(); deadlineMs_ = millis() + LINK_DISCOVERY_TIMEOUT_MS; retries_ = 0;
-  state_ = AppState::MASTER_DISCOVER; display_.show("MASTER SEARCH", "WAIT SLAVE"); Serial.println("ESP-NOW DISCOVER");
+  state_ = AppState::MASTER_DISCOVER; Log::printf("ESP-NOW", "discovery started session=%08lX", session_);
+  display_.show("MASTER SEARCH", "WAIT SLAVE");
 }
 
 ProtocolPacket App::makePacket(MessageType type) const {
@@ -182,7 +246,9 @@ ProtocolPacket App::makePacket(MessageType type) const {
 }
 
 void App::sendCurrent(MessageType type) {
-  ++sequence_; pendingPacket_ = makePacket(type); radio_.sendTo(peer_, pendingPacket_); lastSendMs_ = millis();
+  ++sequence_; pendingPacket_ = makePacket(type);
+  const bool ok = radio_.sendTo(peer_, pendingPacket_); lastSendMs_ = millis();
+  if (!ok) Log::printf("ESP-NOW", "sendCurrent %s FAILED", messageName(type));
 }
 
 bool App::packetForCurrent(const ProtocolPacket &p) const {
@@ -194,7 +260,8 @@ void App::handleRadio() {
   while (radio_.receive(r)) {
     const MessageType type = static_cast<MessageType>(r.packet.type);
     if (state_ != AppState::SLAVE_MEASURE)
-      Serial.printf("ESP-NOW RX type=%u session=%08lX stage=%u seq=%u\n", r.packet.type, r.packet.session, r.packet.stage, r.packet.sequence);
+      Log::printf("ESP-NOW", "RX %s session=%08lX stage=%u seq=%u",
+        messageName(type), r.packet.session, r.packet.stage, r.packet.sequence);
     if (state_ == AppState::SLAVE_READY && type == MessageType::DISCOVER) {
       memcpy(peer_, r.mac, 6); havePeer_ = true; session_ = r.packet.session; stageIndex_ = 0; sequence_ = r.packet.sequence;
       ProtocolPacket ack = makePacket(MessageType::DISCOVER_ACK); ack.sequence = r.packet.sequence; radio_.sendTo(peer_, ack);
@@ -203,7 +270,7 @@ void App::handleRadio() {
     if (state_ == AppState::MASTER_DISCOVER && type == MessageType::DISCOVER_ACK && r.packet.session == session_) {
       memcpy(peer_, r.mac, 6); havePeer_ = true; requestedHz_ = frequencyAt(params_.startHz, params_.endHz, params_.stepHz, stageIndex_);
       sendCurrent(MessageType::PREPARE); state_ = AppState::MASTER_WAIT_READY; retries_ = 0; deadlineMs_ = millis() + LINK_REPLY_TIMEOUT_MS;
-      char mac[20]; Radio::macText(peer_, mac, sizeof(mac)); Serial.printf("SLAVE SELECTED %s\n", mac); continue;
+      char mac[20]; Radio::macText(peer_, mac, sizeof(mac)); Log::printf("ESP-NOW", "Slave selected %s", mac); continue;
     }
     if (state_ == AppState::SLAVE_WAIT_START && type == MessageType::DISCOVER &&
         r.packet.session == session_ && !memcmp(peer_, r.mac, 6)) {
@@ -244,11 +311,15 @@ void App::updateMaster() {
   const uint32_t now = millis();
   if (state_ == AppState::MASTER_DISCOVER) {
     if (now >= deadlineMs_) { finish(false, FailReason::LINK_LOST); return; }
-    if (now - lastSendMs_ >= LINK_RETRY_INTERVAL_MS) { radio_.sendBroadcast(pendingPacket_); lastSendMs_ = now; }
+    if (now - lastSendMs_ >= LINK_RETRY_INTERVAL_MS) {
+      Log::printf("ESP-NOW", "DISCOVER retry=%u", retries_ + 1); radio_.sendBroadcast(pendingPacket_);
+      lastSendMs_ = now; ++retries_;
+    }
     return;
   }
   if (now < deadlineMs_) return;
   if (retries_ >= LINK_PACKET_RETRIES) { finish(false, FailReason::LINK_LOST); return; }
+  Log::printf("ESP-NOW", "%s retry=%u", messageName(static_cast<MessageType>(pendingPacket_.type)), retries_ + 1);
   radio_.sendTo(peer_, pendingPacket_); ++retries_;
   deadlineMs_ = now + (state_ == AppState::MASTER_WAIT_RESULT ?
     params_.testTimeMs * params_.repeats + LINK_REPLY_TIMEOUT_MS : LINK_REPLY_TIMEOUT_MS);
@@ -259,32 +330,39 @@ void App::updateSlave() {
     const MeasureState ms = measurement_.update();
     if (ms != MeasureState::PASS && ms != MeasureState::FAIL) return;
     printStageStats(measurement_.stats(), requestedHz_);
-    pendingPacket_ = makePacket(MessageType::RESULT); pendingPacket_.passed = ms == MeasureState::PASS;
+    pendingPacket_ = makePacket(MessageType::RESULT);
+    pendingPacket_.passed = ms == MeasureState::PASS && measurement_.reason() == FailReason::NONE;
     pendingPacket_.reason = static_cast<uint8_t>(measurement_.reason()); pendingPacket_.periods = measurement_.stats().periods;
     pendingPacket_.minPeriodTicks = measurement_.stats().minPeriod; pendingPacket_.maxPeriodTicks = measurement_.stats().maxPeriod;
     pendingPacket_.sequence = ++sequence_; radio_.sendTo(peer_, pendingPacket_);
+    Log::printf("TEST", "Slave result prepared: %s reason=%s periods=%lu",
+      pendingPacket_.passed ? "PASS" : "FAIL", failName(static_cast<FailReason>(pendingPacket_.reason)), pendingPacket_.periods);
     state_ = AppState::SLAVE_WAIT_ACK; retries_ = 0; deadlineMs_ = millis() + LINK_REPLY_TIMEOUT_MS;
   } else if (state_ == AppState::SLAVE_WAIT_ACK && millis() >= deadlineMs_) {
     if (retries_++ >= LINK_PACKET_RETRIES) finish(false, FailReason::LINK_LOST);
-    else { radio_.sendTo(peer_, pendingPacket_); deadlineMs_ = millis() + LINK_REPLY_TIMEOUT_MS; }
+    else { Log::printf("ESP-NOW", "RESULT retry=%u", retries_); radio_.sendTo(peer_, pendingPacket_); deadlineMs_ = millis() + LINK_REPLY_TIMEOUT_MS; }
   }
 }
 
 void App::sendAbort() { if (havePeer_) sendCurrent(MessageType::ABORT); }
 
-void App::abortTest() { sendAbort(); measurement_.abort(); finish(false, FailReason::ABORTED); }
+void App::abortTest() {
+  Log::event("ACTION", "abort requested: sending ABORT, stopping receiver and PWM");
+  sendAbort(); measurement_.abort(); finish(false, FailReason::ABORTED);
+}
 
 void App::finish(bool pass, FailReason reason) {
+  Log::printf("TEST", "finishing result=%s reason=%s", pass ? "PASS" : "FAIL", failName(reason));
   pwm_.stop(); receiver_.stop();
   if (state_ != AppState::IDLE && state_ != AppState::MENU) radio_.end();
   state_ = AppState::FINISHED; pendingReason_ = reason;
   char one[24];
   if (pass) { snprintf(one, sizeof(one), "PASS %luHz-%lu", params_.startHz, params_.endHz); display_.show(one, "START=REPEAT"); }
   else { snprintf(one, sizeof(one), "FAIL AT %lu", requestedHz_); display_.show(one, failName(reason)); }
-  Serial.printf("TEST %s: %s\n", pass ? "PASS" : "FAIL", failName(reason));
 }
 
 void App::printConfiguration() {
+  if (SERIAL_MINIMAL_LOG) return;
   const char *board = TARGET_IS_C3 ? "ESP32-C3" : "ESP32-S3";
   uint8_t mac[6] = {}; esp_read_mac(mac, ESP_MAC_WIFI_STA);
   Serial.printf("\nOptical Channel Tester | %s | mode=%s\n", board, roleName(static_cast<Role>(settings_.role)));
@@ -300,23 +378,19 @@ void App::printConfiguration() {
 }
 
 uint64_t App::actualNominalTotalUs() {
-  uint64_t total = 0;
-  const uint32_t count = frequencyPointCount(params_.startHz, params_.endHz, params_.stepHz);
-  for (uint32_t i = 0; i < count; ++i) {
-    ActualPwm preview = {};
-    const uint32_t requested = frequencyAt(params_.startHz, params_.endHz, params_.stepHz, i);
-    const uint32_t actualHz = pwm_.preview(requested, params_.dutyPct, preview) ? preview.actualHz : requested;
-    total += (1000000ULL * PWM_SETTLE_CYCLES + actualHz - 1) / actualHz;
-    total += static_cast<uint64_t>(params_.testTimeMs) * 1000ULL * params_.repeats;
-  }
-  return total;
+  // ALL is only an estimate. Do not attach/detach LEDC for every frequency:
+  // large sweeps can perform hundreds of unnecessary driver reconfigurations
+  // immediately before the real test and leave no observable PWM on failure.
+  return nominalTotalUs(params_, PWM_SETTLE_CYCLES);
 }
 
 void App::printStageStats(const StageStats &s, uint32_t hz) {
   if (!s.periods) return;
-  Serial.printf("STATS %luHz periods=%lu period ticks min/avg/max=%lu/%llu/%lu active=%lu/%llu/%lu\n",
-    hz, s.periods, s.minPeriod, s.periodSum / s.periods, s.maxPeriod,
-    s.minActive, s.activeSum / s.periods, s.maxActive);
-  if (s.reason != FailReason::NONE) Serial.printf("FIRST BAD repeat=%u period=%lu f=%.3f duty=%.3f reason=%s\n",
-    s.firstBadRepeat, s.firstBadPeriod, s.badFrequency, s.badDuty, failName(s.reason));
+  const float measuredHz = static_cast<float>(receiver_.tickHz()) * s.periods / s.periodSum;
+  const float measuredDuty = 100.0f * s.activeSum / s.periodSum;
+  const char *status = s.reason == FailReason::NONE ? "PASS" :
+    (s.reason == FailReason::DATA_LOST ? "DATA_LOST" : "FAIL");
+  Log::printf("RESULT", "%luHz %s periods=%lu measured=%.2fHz duty=%.2f%% lost=%lu%s%s",
+    hz, status, s.periods, measuredHz, measuredDuty, s.lostItems,
+    s.reason == FailReason::NONE ? "" : " reason=", s.reason == FailReason::NONE ? "" : failName(s.reason));
 }

OpticalChannelTester/App.h

@@ -64,5 +64,7 @@ class App {
   uint8_t retries_ = 0;
   ProtocolPacket pendingPacket_ = {};
   bool initialized_ = false, bootResetCandidate_ = false;
+  bool sweepHadDataLoss_ = false;
+  uint32_t firstDataLossHz_ = 0;
   uint32_t bootCheckStartedMs_ = 0;
 };

OpticalChannelTester/Config.h

@@ -26,6 +26,9 @@ constexpr uint8_t GPIO_SCL = 9;
 constexpr uint8_t OLED_ADDRESS = 0x3C;
 constexpr uint8_t ESPNOW_WIFI_CHANNEL = 6;
 constexpr uint32_t SERIAL_BAUD = 115200;
+constexpr bool SERIAL_ACTION_LOG = true;
+constexpr bool SERIAL_LOG_TIMESTAMPS = true;
+constexpr bool SERIAL_MINIMAL_LOG = true;
 
 #define BUTTON_ACTIVE_LEVEL LOW
 #define RX_SIGNAL_INVERTED false
@@ -43,11 +46,19 @@ constexpr uint32_t LINK_REPLY_TIMEOUT_MS = 800;
 constexpr uint8_t LINK_PACKET_RETRIES = 3;
 constexpr uint32_t LINK_RETRY_INTERVAL_MS = 100;
 constexpr uint8_t NO_SIGNAL_TIMEOUT_PERIODS = 8;
+constexpr uint16_t RMT_MIN_RECEIVE_SYMBOLS = 48;
+constexpr uint16_t RMT_MAX_RECEIVE_SYMBOLS = 512;
+constexpr uint32_t RMT_TARGET_CHUNK_US = 5000;
+constexpr uint8_t RMT_QUEUE_BLOCKS = 8;
+constexpr uint16_t PERIOD_BATCH_SIZE = 128;
 
-constexpr uint32_t C3_STRICT_MAX_HZ = 100000;
+constexpr uint32_t C3_STRICT_MAX_HZ = 1000000;
 constexpr uint32_t S3_STRICT_MAX_HZ = 1000000;
-constexpr uint32_t C3_GUARANTEED_HZ = 10000;
 constexpr uint32_t CAPTURE_RESOLUTION_HZ = 80000000;
+// Arduino-ESP32 uses the 40 MHz crystal as the default LEDC clock on C3/S3.
+// Keep this explicit so the resolution calculation never asks LEDC for an
+// impossible frequency/resolution combination.
+constexpr uint32_t LEDC_SOURCE_CLOCK_HZ = 40000000;
 constexpr uint8_t LEDC_CHANNEL = 0;
 constexpr uint8_t LEDC_MAX_BITS = 14;
 

OpticalChannelTester/Core.cpp

@@ -11,7 +11,7 @@ const char *roleName(Role r) {
 const char *failName(FailReason r) {
   static const char *names[] = {"NONE", "NO SIGNAL", "PERIOD OUT", "DUTY OUT",
     "EXTRA EDGE", "GLITCH", "LOST EDGE", "TOO FEW PERIODS", "LINK LOST",
-    "UNSUPPORTED", "RESOLUTION", "ABORTED"};
+    "UNSUPPORTED", "RESOLUTION", "ABORTED", "DATA LOST"};
   const uint8_t i = static_cast<uint8_t>(r);
   return i < (sizeof(names) / sizeof(names[0])) ? names[i] : "UNKNOWN";
 }
@@ -63,6 +63,15 @@ bool dutyWithin(float measured, float expected, float tolerance) {
   return fabsf(measured - expected) <= tolerance + 0.0001f;
 }
 
+uint8_t choosePwmResolution(uint32_t frequencyHz, uint32_t sourceClockHz,
+                            uint8_t maxBits) {
+  if (!frequencyHz || !sourceClockHz || !maxBits) return 0;
+  uint8_t bits = maxBits;
+  while (bits > 1 && static_cast<uint64_t>(frequencyHz) * (1ULL << bits) > sourceClockHz)
+    --bits;
+  return bits;
+}
+
 FailReason validateResolution(uint32_t frequencyHz, float dutyPct, float accuracyPct,
                               uint32_t captureHz, uint8_t pwmBits) {
   if (!frequencyHz || !captureHz || !pwmBits) return FailReason::RESOLUTION;
@@ -72,8 +81,10 @@ FailReason validateResolution(uint32_t frequencyHz, float dutyPct, float accurac
   if (periodTicks < 4.0f || activeTicks < 2.0f || inactiveTicks < 2.0f) return FailReason::RESOLUTION;
   const float timerPeriodError = 100.0f / periodTicks;
   const float timerDutyError = 100.0f / periodTicks;
-  const float pwmDutyStep = 100.0f / static_cast<float>((1UL << pwmBits) - 1UL);
-  return (timerPeriodError > accuracyPct || timerDutyError > accuracyPct || pwmDutyStep > accuracyPct)
+  // Measurement uses the duty actually programmed into LEDC. A coarse PWM
+  // step is not itself an error when the requested value (e.g. 50%) is exactly
+  // representable; only the selected value's actual quantization matters.
+  return (timerPeriodError > accuracyPct || timerDutyError > accuracyPct)
     ? FailReason::RESOLUTION : FailReason::NONE;
 }
 
@@ -99,3 +110,55 @@ FailReason evaluatePeriod(const PulsePeriod &p, uint32_t tickHz, float expectedH
   return reason;
 }
 
+bool makePeriodLimits(uint32_t expectedHz, float expectedDuty, float tolerance,
+                      uint32_t tickHz, PeriodLimits &limits) {
+  if (!expectedHz || !tickHz || tolerance < 0.0f || tolerance >= 100.0f ||
+      expectedDuty <= 0.0f || expectedDuty >= 100.0f) return false;
+  const uint32_t toleranceX100 = static_cast<uint32_t>(lroundf(tolerance * 100.0f));
+  const uint32_t dutyX100 = static_cast<uint32_t>(lroundf(expectedDuty * 100.0f));
+  const uint64_t numerator = static_cast<uint64_t>(tickHz) * 10000ULL;
+  const uint64_t highDenominator = static_cast<uint64_t>(expectedHz) * (10000U + toleranceX100);
+  const uint64_t lowDenominator = static_cast<uint64_t>(expectedHz) * (10000U - toleranceX100);
+  limits.minPeriodTicks = static_cast<uint32_t>((numerator + highDenominator - 1U) / highDenominator);
+  limits.maxPeriodTicks = static_cast<uint32_t>(numerator / lowDenominator);
+  limits.minDutyX100 = dutyX100 > toleranceX100 ? dutyX100 - toleranceX100 : 0;
+  limits.maxDutyX100 = dutyX100 + toleranceX100;
+  return limits.minPeriodTicks && limits.maxPeriodTicks >= limits.minPeriodTicks;
+}
+
+FailReason evaluatePeriodFast(const PulsePeriod &p, uint32_t tickHz,
+                              const PeriodLimits &limits, uint8_t repeat,
+                              StageStats &s) {
+  if (!p.periodTicks || p.activeTicks >= p.periodTicks) return FailReason::EXTRA_EDGE;
+  ++s.periods;
+  s.periodSum += p.periodTicks; s.activeSum += p.activeTicks;
+  if (p.periodTicks < s.minPeriod) s.minPeriod = p.periodTicks;
+  if (p.periodTicks > s.maxPeriod) s.maxPeriod = p.periodTicks;
+  if (p.activeTicks < s.minActive) s.minActive = p.activeTicks;
+  if (p.activeTicks > s.maxActive) s.maxActive = p.activeTicks;
+
+  FailReason reason = FailReason::NONE;
+  if (p.periodTicks < limits.minPeriodTicks || p.periodTicks > limits.maxPeriodTicks) {
+    reason = FailReason::PERIOD_OUT;
+  } else {
+    // The configured range (>= 1 kHz at 80 MHz capture) fits these products
+    // into 32 bits. Keep a 64-bit fallback for unusually slow external input.
+    if (p.periodTicks <= UINT32_MAX / 10000U && limits.maxDutyX100 <= 10000U) {
+      const uint32_t scaledActive = p.activeTicks * 10000U;
+      const uint32_t minActive = p.periodTicks * limits.minDutyX100;
+      const uint32_t maxActive = p.periodTicks * limits.maxDutyX100;
+      if (scaledActive < minActive || scaledActive > maxActive) reason = FailReason::DUTY_OUT;
+    } else {
+      const uint64_t scaledActive = static_cast<uint64_t>(p.activeTicks) * 10000ULL;
+      const uint64_t minActive = static_cast<uint64_t>(p.periodTicks) * limits.minDutyX100;
+      const uint64_t maxActive = static_cast<uint64_t>(p.periodTicks) * limits.maxDutyX100;
+      if (scaledActive < minActive || scaledActive > maxActive) reason = FailReason::DUTY_OUT;
+    }
+  }
+  if (reason != FailReason::NONE && s.reason == FailReason::NONE) {
+    s.reason = reason; s.firstBadPeriod = s.periods; s.firstBadRepeat = repeat;
+    s.badFrequency = static_cast<float>(tickHz) / p.periodTicks;
+    s.badDuty = 100.0f * p.activeTicks / p.periodTicks;
+  }
+  return reason;
+}

OpticalChannelTester/Core.h

@@ -6,7 +6,7 @@
 enum class Role : uint8_t { SOLO, MASTER, SLAVE };
 enum class FailReason : uint8_t {
   NONE, NO_SIGNAL, PERIOD_OUT, DUTY_OUT, EXTRA_EDGE, GLITCH, LOST_EDGE,
-  TOO_FEW_PERIODS, LINK_LOST, UNSUPPORTED, RESOLUTION, ABORTED
+  TOO_FEW_PERIODS, LINK_LOST, UNSUPPORTED, RESOLUTION, ABORTED, DATA_LOST
 };
 
 const char *roleName(Role role);
@@ -53,19 +53,33 @@ struct StageStats {
   uint8_t firstBadRepeat;
   float badFrequency;
   float badDuty;
+  uint32_t lostItems;
   FailReason reason;
   void reset();
 };
 
+struct PeriodLimits {
+  uint32_t minPeriodTicks;
+  uint32_t maxPeriodTicks;
+  uint32_t minDutyX100;
+  uint32_t maxDutyX100;
+};
+
 uint32_t settingsChecksum(const Settings &s);
 uint32_t frequencyPointCount(uint32_t startHz, uint32_t endHz, uint32_t stepHz);
 uint32_t frequencyAt(uint32_t startHz, uint32_t endHz, uint32_t stepHz, uint32_t index);
 uint64_t nominalTotalUs(const TestParams &p, uint32_t settleCycles);
 bool periodWithin(float measuredHz, float expectedHz, float tolerancePct);
 bool dutyWithin(float measuredPct, float expectedPct, float tolerancePct);
+uint8_t choosePwmResolution(uint32_t frequencyHz, uint32_t sourceClockHz,
+                            uint8_t maxBits);
 FailReason validateResolution(uint32_t frequencyHz, float dutyPct, float accuracyPct,
                               uint32_t captureResolutionHz, uint8_t pwmBits);
 FailReason evaluatePeriod(const PulsePeriod &period, uint32_t tickHz, float expectedHz,
                           float expectedDuty, float tolerancePct, uint8_t repeat,
                           StageStats &stats);
-
+bool makePeriodLimits(uint32_t expectedHz, float expectedDuty, float tolerancePct,
+                      uint32_t tickHz, PeriodLimits &limits);
+FailReason evaluatePeriodFast(const PulsePeriod &period, uint32_t tickHz,
+                              const PeriodLimits &limits, uint8_t repeat,
+                              StageStats &stats);

OpticalChannelTester/Display.cpp

@@ -1,5 +1,6 @@
 #include "Display.h"
 #include "Config.h"
+#include "Log.h"
 #include <Wire.h>
 #include <string.h>
 
@@ -9,6 +10,7 @@ bool Display::begin() {
   Wire.begin(GPIO_SDA, GPIO_SCL);
   ok_ = oled_.begin(SSD1306_SWITCHCAPVCC, OLED_ADDRESS);
   if (ok_) { oled_.setTextColor(SSD1306_WHITE); oled_.setTextSize(1); }
+  Log::printf("OLED", "initialization %s, I2C address=0x%02X", ok_ ? "OK" : "FAILED", OLED_ADDRESS);
   return ok_;
 }
 
@@ -22,9 +24,11 @@ void Display::fit(char *s) {
 }
 
 void Display::show(const char *a, const char *b) {
-  if (!ok_) return;
   char one[32], two[32];
   snprintf(one, sizeof(one), "%s", a ? a : ""); snprintf(two, sizeof(two), "%s", b ? b : "");
+  // Serial is the primary UI mirror and remains available when OLED is absent.
+  Log::printf("UI", "%s | %s", one, two);
+  if (!ok_) return;
   fit(one); fit(two);
   oled_.clearDisplay(); oled_.setCursor(0, 3); oled_.print(one);
   oled_.setCursor(0, 19); oled_.print(two); oled_.display();
@@ -41,4 +45,3 @@ void Display::formatDuration(uint64_t us, char *out, size_t n) {
   if (minutes < 60) snprintf(out, n, "%02llu:%02llu", minutes, (us / 1000000ULL) % 60ULL);
   else snprintf(out, n, "%llu:%02llu", minutes / 60ULL, minutes % 60ULL);
 }
-

OpticalChannelTester/Log.cpp

@@ -0,0 +1,24 @@
+#include "Log.h"
+#include "Config.h"
+#include <stdarg.h>
+#include <string.h>
+
+namespace Log {
+void event(const char *component, const char *message) {
+  if (!SERIAL_ACTION_LOG) return;
+  if (SERIAL_MINIMAL_LOG && strcmp(component, "INPUT") && strcmp(component, "UI") &&
+      strcmp(component, "CONFIG") && strcmp(component, "RESULT")) return;
+  if (SERIAL_LOG_TIMESTAMPS) Serial.printf("[%10lu][%-8s] %s\n", millis(), component, message);
+  else Serial.printf("[%-8s] %s\n", component, message);
+}
+
+void printf(const char *component, const char *format, ...) {
+  if (!SERIAL_ACTION_LOG) return;
+  char text[192];
+  va_list args;
+  va_start(args, format);
+  vsnprintf(text, sizeof(text), format, args);
+  va_end(args);
+  event(component, text);
+}
+}

OpticalChannelTester/Log.h

@@ -0,0 +1,9 @@
+#pragma once
+#include <Arduino.h>
+
+namespace Log {
+void event(const char *component, const char *message);
+void printf(const char *component, const char *format, ...)
+  __attribute__((format(printf, 2, 3)));
+}
+

OpticalChannelTester/Measurement.cpp

@@ -4,12 +4,17 @@
 
 bool Measurement::start(float hz, float duty, float tolerance, uint32_t timeMs,
                         uint8_t repeats, uint8_t settleCycles) {
-  if (!hz || !timeMs || !repeats || repeats > 10 || !receiver_.start(static_cast<uint32_t>(hz))) return false;
-  expectedHz_ = hz; expectedDuty_ = duty; tolerance_ = tolerance;
+  expectedHz_ = static_cast<uint32_t>(hz + 0.5f);
+  if (!expectedHz_ || !timeMs || !repeats || repeats > 10 ||
+      !makePeriodLimits(expectedHz_, duty, tolerance, receiver_.tickHz(), limits_) ||
+      !receiver_.start(expectedHz_)) return false;
   timeMs_ = timeMs; repeats_ = repeats; settleLeft_ = settleCycles;
   stats_.reset(); memset(repeatPeriods_, 0, sizeof(repeatPeriods_));
   measurementStartTick_ = deadlineTick_ = 0; startedMs_ = millis();
   measurementStartMs_ = lastPeriodMs_ = 0;
+  currentRepeat_ = 0;
+  expectedPeriodMs_ = static_cast<uint32_t>((1000ULL + expectedHz_ - 1U) / expectedHz_);
+  if (!expectedPeriodMs_) expectedPeriodMs_ = 1;
   state_ = MeasureState::SETTLING; return true;
 }
 
@@ -18,49 +23,65 @@ void Measurement::fail(FailReason reason) {
   receiver_.stop(); state_ = MeasureState::FAIL;
 }
 
+void Measurement::completeWindow() {
+  receiver_.stop();
+  stats_.lostItems += receiver_.takeDroppedItems();
+  if (receiver_.overflowed()) { fail(FailReason::GLITCH); return; }
+  for (uint8_t i = 0; i < repeats_; ++i) if (!repeatPeriods_[i]) {
+    fail(FailReason::TOO_FEW_PERIODS); return;
+  }
+  if (stats_.lostItems && stats_.reason == FailReason::NONE) stats_.reason = FailReason::DATA_LOST;
+  state_ = MeasureState::PASS;
+}
+
 MeasureState Measurement::update() {
   if (state_ != MeasureState::SETTLING && state_ != MeasureState::RUNNING) return state_;
   if (receiver_.overflowed()) { fail(FailReason::GLITCH); return state_; }
-  PulsePeriod period;
-  while (receiver_.poll(period)) {
-    if (state_ == MeasureState::SETTLING) {
-      if (settleLeft_) --settleLeft_;
-      if (!settleLeft_) {
-        measurementStartTick_ = period.startTick + period.periodTicks;
-        repeatTicks_ = static_cast<uint64_t>(receiver_.tickHz()) * timeMs_ / 1000ULL;
-        deadlineTick_ = measurementStartTick_ + repeatTicks_ * repeats_;
-        stats_.reset(); measurementStartMs_ = lastPeriodMs_ = millis(); state_ = MeasureState::RUNNING;
+  bool receivedPeriod = false;
+  for (;;) {
+    const size_t periodCount = receiver_.readPeriods(periodBatch_, PERIOD_BATCH_SIZE);
+    stats_.lostItems += receiver_.takeDroppedItems();
+    if (!periodCount) break;
+    receivedPeriod = true;
+    for (size_t periodIndex = 0; periodIndex < periodCount; ++periodIndex) {
+      const PulsePeriod &period = periodBatch_[periodIndex];
+      if (state_ == MeasureState::SETTLING) {
+        if (settleLeft_) --settleLeft_;
+        if (!settleLeft_) {
+          measurementStartTick_ = period.startTick + period.periodTicks;
+          repeatTicks_ = static_cast<uint64_t>(receiver_.tickHz()) * timeMs_ / 1000ULL;
+          deadlineTick_ = measurementStartTick_ + repeatTicks_ * repeats_;
+          nextRepeatTick_ = measurementStartTick_ + repeatTicks_;
+          stats_.reset(); measurementStartMs_ = lastPeriodMs_ = millis(); state_ = MeasureState::RUNNING;
+        }
+        continue;
       }
-      continue;
+      const uint64_t endTick = period.startTick + period.periodTicks;
+      if (period.startTick < measurementStartTick_) continue; // leading incomplete period
+      if (endTick > deadlineTick_) { completeWindow(); return state_; } // trailing incomplete period
+      while (currentRepeat_ + 1U < repeats_ && period.startTick >= nextRepeatTick_) {
+        ++currentRepeat_; nextRepeatTick_ += repeatTicks_;
+      }
+      ++repeatPeriods_[currentRepeat_];
+      const FailReason r = evaluatePeriodFast(period, receiver_.tickHz(), limits_, currentRepeat_ + 1, stats_);
+      if (r != FailReason::NONE) { fail(r); return state_; }
     }
-    const uint64_t endTick = period.startTick + period.periodTicks;
-    if (period.startTick < measurementStartTick_) continue; // leading incomplete period
-    if (endTick > deadlineTick_) break;                     // trailing incomplete period
-    uint8_t repeat = static_cast<uint8_t>((period.startTick - measurementStartTick_) / repeatTicks_);
-    if (repeat >= repeats_) repeat = repeats_ - 1;
-    ++repeatPeriods_[repeat];
-    lastPeriodMs_ = millis();
-    const FailReason r = evaluatePeriod(period, receiver_.tickHz(), expectedHz_, expectedDuty_,
-                                        tolerance_, repeat + 1, stats_);
-    if (r != FailReason::NONE) { fail(r); return state_; }
   }
-  const uint64_t expectedPeriodMs = static_cast<uint64_t>(1000.0f / expectedHz_) + 1;
-  const uint64_t settleTimeout = (static_cast<uint64_t>(PWM_SETTLE_CYCLES + NO_SIGNAL_TIMEOUT_PERIODS) *
-                                  expectedPeriodMs) + 20;
+  if (receivedPeriod && state_ == MeasureState::RUNNING) lastPeriodMs_ = millis();
+  const uint64_t edgeBasedTimeout =
+    static_cast<uint64_t>(PWM_SETTLE_CYCLES + NO_SIGNAL_TIMEOUT_PERIODS) * expectedPeriodMs_ + 20;
+  const uint64_t rmtBatchTimeout =
+    static_cast<uint64_t>(RMT_MIN_RECEIVE_SYMBOLS + NO_SIGNAL_TIMEOUT_PERIODS) * expectedPeriodMs_ + 20;
+  const uint64_t settleTimeout = edgeBasedTimeout > rmtBatchTimeout ? edgeBasedTimeout : rmtBatchTimeout;
   if (state_ == MeasureState::SETTLING && millis() - startedMs_ > settleTimeout) fail(FailReason::NO_SIGNAL);
   if (state_ == MeasureState::RUNNING && measurementStartTick_) {
     const uint32_t now = millis();
     const uint32_t totalMs = timeMs_ * repeats_;
-    const uint32_t edgeTimeoutMs = static_cast<uint32_t>(expectedPeriodMs * NO_SIGNAL_TIMEOUT_PERIODS + 2);
+    const uint32_t edgeTimeoutMs = expectedPeriodMs_ * NO_SIGNAL_TIMEOUT_PERIODS + 2;
     if (now - measurementStartMs_ < totalMs && now - lastPeriodMs_ > edgeTimeoutMs) {
       fail(FailReason::LOST_EDGE); return state_;
     }
-    if (now - measurementStartMs_ > totalMs + expectedPeriodMs + 2) {
-      for (uint8_t i = 0; i < repeats_; ++i) if (!repeatPeriods_[i]) {
-        fail(FailReason::TOO_FEW_PERIODS); return state_;
-      }
-      receiver_.stop(); state_ = MeasureState::PASS;
-    }
+    if (now - measurementStartMs_ > totalMs + expectedPeriodMs_ + 2) completeWindow();
   }
   return state_;
 }

OpticalChannelTester/Measurement.h

@@ -15,13 +15,17 @@ class Measurement {
   const StageStats &stats() const { return stats_; }
  private:
   void fail(FailReason reason);
+  void completeWindow();
   PulseReceiver &receiver_;
   MeasureState state_ = MeasureState::IDLE;
   StageStats stats_ = {};
-  float expectedHz_ = 0, expectedDuty_ = 0, tolerance_ = 0;
+  PeriodLimits limits_ = {};
+  uint32_t expectedHz_ = 0;
   uint32_t timeMs_ = 0;
-  uint8_t repeats_ = 0, settleLeft_ = 0;
-  uint64_t measurementStartTick_ = 0, deadlineTick_ = 0, repeatTicks_ = 0;
+  uint8_t repeats_ = 0, settleLeft_ = 0, currentRepeat_ = 0;
+  uint64_t measurementStartTick_ = 0, deadlineTick_ = 0, repeatTicks_ = 0, nextRepeatTick_ = 0;
   uint32_t startedMs_ = 0, measurementStartMs_ = 0, lastPeriodMs_ = 0;
+  uint32_t expectedPeriodMs_ = 1;
   uint32_t repeatPeriods_[10] = {};
+  PulsePeriod periodBatch_[PERIOD_BATCH_SIZE] = {};
 };

OpticalChannelTester/Protocol.cpp

@@ -1,6 +1,13 @@
 #include "Protocol.h"
 #include <stddef.h>
 
+const char *messageName(MessageType type) {
+  static const char *names[] = {"DISCOVER", "DISCOVER_ACK", "PREPARE", "READY",
+    "START_STAGE", "RESULT", "ACK", "ABORT"};
+  const uint8_t index = static_cast<uint8_t>(type);
+  return index < sizeof(names) / sizeof(names[0]) ? names[index] : "UNKNOWN";
+}
+
 uint16_t packetCrc(const ProtocolPacket &p) {
   const uint8_t *data = reinterpret_cast<const uint8_t *>(&p);
   uint16_t crc = 0xFFFF;
@@ -19,4 +26,3 @@ bool validPacket(const ProtocolPacket &p) {
   return p.magic == PROTOCOL_MAGIC && p.version == PROTOCOL_VERSION &&
     p.type <= static_cast<uint8_t>(MessageType::ABORT) && p.crc == packetCrc(p);
 }
-

OpticalChannelTester/Protocol.h

@@ -8,6 +8,8 @@ enum class MessageType : uint8_t {
   DISCOVER, DISCOVER_ACK, PREPARE, READY, START_STAGE, RESULT, ACK, ABORT
 };
 
+const char *messageName(MessageType type);
+
 #pragma pack(push, 1)
 struct ProtocolPacket {
   uint16_t magic;

OpticalChannelTester/Pwm.cpp

@@ -1,37 +1,29 @@
 #include "Pwm.h"
 #include "Config.h"
+#include "Core.h"
 
-void PwmGenerator::begin() { pinMode(GPIO_PWM, OUTPUT); stop(); }
+void PwmGenerator::begin() {
+  // Match LEDC_SOURCE_CLOCK_HZ and make the timer calculation deterministic.
+  ledcSetClockSource(LEDC_USE_XTAL_CLK);
+  pinMode(GPIO_PWM, OUTPUT);
+  stop();
+}
 
 bool PwmGenerator::start(uint32_t hz, uint8_t dutyPct, ActualPwm &a) {
   stop();
-  uint8_t bits = LEDC_MAX_BITS;
-  while (bits > 1 && static_cast<uint64_t>(hz) * (1ULL << bits) > 80000000ULL) --bits;
+  const uint8_t bits = choosePwmResolution(hz, LEDC_SOURCE_CLOCK_HZ, LEDC_MAX_BITS);
+  if (!bits) return false;
   if (!ledcAttachChannel(GPIO_PWM, hz, bits, LEDC_CHANNEL)) return false;
-  const uint32_t top = (1UL << bits) - 1UL;
-  const uint32_t duty = (static_cast<uint64_t>(top) * dutyPct + 50U) / 100U;
+  const uint32_t levels = 1UL << bits;
+  const uint32_t duty = (static_cast<uint64_t>(levels) * dutyPct + 50U) / 100U;
   if (!ledcWriteChannel(LEDC_CHANNEL, duty)) { ledcDetach(GPIO_PWM); return false; }
   const uint32_t actualHz = ledcReadFreq(GPIO_PWM);
   if (!actualHz) { ledcDetach(GPIO_PWM); return false; }
-  a = {hz, actualHz, 100.0f * duty / top, bits};
+  a = {hz, actualHz, 100.0f * duty / levels, bits};
   running_ = true;
   return true;
 }
 
-bool PwmGenerator::preview(uint32_t hz, uint8_t dutyPct, ActualPwm &a) {
-  stop();
-  uint8_t bits = LEDC_MAX_BITS;
-  while (bits > 1 && static_cast<uint64_t>(hz) * (1ULL << bits) > 80000000ULL) --bits;
-  if (!ledcAttachChannel(GPIO_PWM, hz, bits, LEDC_CHANNEL)) return false;
-  ledcWriteChannel(LEDC_CHANNEL, 0); // query hardware without emitting test pulses
-  const uint32_t actualHz = ledcReadFreq(GPIO_PWM);
-  const uint32_t top = (1UL << bits) - 1UL;
-  const uint32_t duty = (static_cast<uint64_t>(top) * dutyPct + 50U) / 100U;
-  a = {hz, actualHz, 100.0f * duty / top, bits};
-  ledcDetach(GPIO_PWM); pinMode(GPIO_PWM, OUTPUT); digitalWrite(GPIO_PWM, PWM_SAFE_LEVEL);
-  return actualHz != 0;
-}
-
 void PwmGenerator::stop() {
   if (running_) ledcDetach(GPIO_PWM);
   pinMode(GPIO_PWM, OUTPUT); digitalWrite(GPIO_PWM, PWM_SAFE_LEVEL);

OpticalChannelTester/Pwm.h

@@ -6,7 +6,6 @@ struct ActualPwm { uint32_t requestedHz; uint32_t actualHz; float actualDutyPct;
 class PwmGenerator {
  public:
   void begin();
-  bool preview(uint32_t frequencyHz, uint8_t dutyPct, ActualPwm &actual);
   bool start(uint32_t frequencyHz, uint8_t dutyPct, ActualPwm &actual);
   void stop();
   bool running() const { return running_; }

OpticalChannelTester/Radio.cpp

@@ -1,5 +1,6 @@
 #include "Radio.h"
 #include "Config.h"
+#include "Log.h"
 #include <WiFi.h>
 #include <esp_wifi.h>
 #include <string.h>
@@ -8,21 +9,26 @@ Radio *Radio::instance_ = nullptr;
 static const uint8_t BROADCAST_MAC[6] = {0xff, 0xff, 0xff, 0xff, 0xff, 0xff};
 
 bool Radio::begin() {
-  if (active_) return true;
+  if (active_) { Log::event("ESP-NOW", "already active"); return true; }
   WiFi.mode(WIFI_STA); WiFi.disconnect();
-  if (esp_wifi_set_channel(ESPNOW_WIFI_CHANNEL, WIFI_SECOND_CHAN_NONE) != ESP_OK) return false;
+  if (esp_wifi_set_channel(ESPNOW_WIFI_CHANNEL, WIFI_SECOND_CHAN_NONE) != ESP_OK) {
+    Log::event("ESP-NOW", "Wi-Fi channel setup FAILED"); return false;
+  }
   queue_ = xQueueCreate(8, sizeof(ReceivedPacket));
-  if (!queue_ || esp_now_init() != ESP_OK) return false;
+  if (!queue_ || esp_now_init() != ESP_OK) { Log::event("ESP-NOW", "initialization FAILED"); return false; }
   instance_ = this;
   if (esp_now_register_recv_cb(onReceive) != ESP_OK) { end(); return false; }
   active_ = true;
-  return ensurePeer(BROADCAST_MAC);
+  const bool ok = ensurePeer(BROADCAST_MAC);
+  Log::printf("ESP-NOW", "started channel=%u broadcast-peer=%s", ESPNOW_WIFI_CHANNEL, ok ? "OK" : "FAILED");
+  return ok;
 }
 
 void Radio::end() {
   if (active_) { esp_now_unregister_recv_cb(); esp_now_deinit(); }
   if (queue_) { vQueueDelete(queue_); queue_ = nullptr; }
   active_ = false; if (instance_ == this) instance_ = nullptr;
+  Log::event("ESP-NOW", "stopped");
 }
 
 bool Radio::ensurePeer(const uint8_t mac[6]) {
@@ -35,9 +41,16 @@ bool Radio::ensurePeer(const uint8_t mac[6]) {
 bool Radio::sendBroadcast(ProtocolPacket p) { return sendTo(BROADCAST_MAC, p); }
 
 bool Radio::sendTo(const uint8_t mac[6], ProtocolPacket p) {
-  if (!active_ || !ensurePeer(mac)) return false;
+  char peer[20]; macText(mac, peer, sizeof(peer));
+  if (!active_ || !ensurePeer(mac)) {
+    Log::printf("ESP-NOW", "TX %s to %s FAILED: inactive/peer", messageName(static_cast<MessageType>(p.type)), peer);
+    return false;
+  }
   finalizePacket(p);
-  return esp_now_send(mac, reinterpret_cast<const uint8_t *>(&p), sizeof(p)) == ESP_OK;
+  const bool ok = esp_now_send(mac, reinterpret_cast<const uint8_t *>(&p), sizeof(p)) == ESP_OK;
+  Log::printf("ESP-NOW", "TX %s to %s session=%08lX stage=%u seq=%u %s",
+    messageName(static_cast<MessageType>(p.type)), peer, p.session, p.stage, p.sequence, ok ? "QUEUED" : "FAILED");
+  return ok;
 }
 
 bool Radio::receive(ReceivedPacket &r) {

OpticalChannelTester/Receiver.cpp

@@ -16,14 +16,18 @@ uint32_t PulseReceiver::tickHz() const {
 
 bool PulseReceiver::begin() {
 #if OPTICAL_USE_RMT_DMA
-  queue_ = xQueueCreate(16, sizeof(SymbolBlock));
+  queue_ = xQueueCreate(RMT_QUEUE_BLOCKS, sizeof(SymbolBlock));
   rmt_rx_channel_config_t cfg = {};
   cfg.clk_src = RMT_CLK_SRC_DEFAULT; cfg.resolution_hz = CAPTURE_RESOLUTION_HZ;
-  cfg.mem_block_symbols = 512; cfg.gpio_num = static_cast<gpio_num_t>(GPIO_RX);
+  cfg.gpio_num = static_cast<gpio_num_t>(GPIO_RX);
   cfg.flags.invert_in = RX_SIGNAL_INVERTED;
 #if CONFIG_IDF_TARGET_ESP32S3
+  cfg.mem_block_symbols = 512;
   cfg.flags.with_dma = true;
 #else
+  // C3 has 48 RMT symbols per channel and no RMT DMA. A request for 512
+  // consumes all available blocks and fails with "no free rx channels".
+  cfg.mem_block_symbols = RMT_MIN_RECEIVE_SYMBOLS;
   cfg.flags.with_dma = false; // C3 uses hardware RMT ping-pong partial reception
 #endif
   if (!queue_ || rmt_new_rx_channel(&cfg, &channel_) != ESP_OK) return false;
@@ -42,13 +46,20 @@ bool PulseReceiver::begin() {
 bool PulseReceiver::start(uint32_t expectedHz) {
   resetStream();
 #if OPTICAL_USE_RMT_DMA
+  // In partial RX mode the callback is delivered when this user buffer fills.
+  // Keep chunks near 5 ms so low-frequency input is reported before NO SIGNAL.
+  uint64_t symbols = (static_cast<uint64_t>(expectedHz) * RMT_TARGET_CHUNK_US + 999999ULL) / 1000000ULL;
+  if (symbols < RMT_MIN_RECEIVE_SYMBOLS) symbols = RMT_MIN_RECEIVE_SYMBOLS;
+  if (symbols > RMT_MAX_RECEIVE_SYMBOLS) symbols = RMT_MAX_RECEIVE_SYMBOLS;
+  receiveChunkSymbols_ = static_cast<uint16_t>(symbols);
   if (rmt_enable(channel_) != ESP_OK) return false;
   rmt_receive_config_t cfg = {};
   cfg.signal_range_min_ns = 20;
   const uint64_t maxNs = 4000000000ULL / (expectedHz ? expectedHz : 1);
   cfg.signal_range_max_ns = maxNs > 100000000ULL ? 100000000UL : static_cast<uint32_t>(maxNs);
   cfg.flags.en_partial_rx = true;
-  if (rmt_receive(channel_, dmaBuffer_, sizeof(dmaBuffer_), &cfg) != ESP_OK) {
+  if (rmt_receive(channel_, receiveBuffer_,
+                  receiveChunkSymbols_ * sizeof(receiveBuffer_[0]), &cfg) != ESP_OK) {
     rmt_disable(channel_); return false;
   }
 #else
@@ -66,7 +77,7 @@ void PulseReceiver::stop() {
 
 void PulseReceiver::resetStream() {
   if (queue_) xQueueReset(queue_);
-  overflow_ = false; haveRise_ = haveFall_ = haveRawTick_ = false;
+  overflow_ = false; droppedItems_ = 0; haveRise_ = haveFall_ = haveRawTick_ = false;
   lastRawTick_ = 0; tickEpoch_ = rise_ = fall_ = 0;
 #if OPTICAL_USE_RMT_DMA
   block_ = {}; blockIndex_ = 0; phase_ = 0; haveLevel_ = false; level_ = false; rmtTick_ = 0;
@@ -86,7 +97,11 @@ bool PulseReceiver::consumeEdge(const Edge &e, PulsePeriod &out) {
     out = {rise_, period, active}; rise_ = tick; haveFall_ = false;
     return true;
   }
-  if (!haveRise_ || haveFall_) { overflow_ = true; return false; }
+  // Reception can begin in the middle of a HIGH pulse. In that case the first
+  // observable edge is falling and there is no complete period to validate.
+  // Ignore only this leading partial pulse and synchronize on the next rise.
+  if (!haveRise_) return false;
+  if (haveFall_) { overflow_ = true; return false; }
   fall_ = tick; haveFall_ = true; return false;
 }
 
@@ -94,17 +109,22 @@ bool PulseReceiver::overflowed() {
   const bool value = overflow_; overflow_ = false; return value;
 }
 
+uint32_t PulseReceiver::takeDroppedItems() {
+  return __atomic_exchange_n(&droppedItems_, 0, __ATOMIC_RELAXED);
+}
+
 #if OPTICAL_USE_RMT_DMA
 bool IRAM_ATTR PulseReceiver::onRmt(rmt_channel_handle_t, const rmt_rx_done_event_data_t *data, void *ctx) {
   PulseReceiver *self = static_cast<PulseReceiver *>(ctx);
   BaseType_t wake = pdFALSE;
   size_t offset = 0;
   while (offset < data->num_symbols) {
-    SymbolBlock b = {};
+    SymbolBlock &b = self->isrBlock_;
     b.count = static_cast<uint16_t>((data->num_symbols - offset) > BLOCK_SYMBOLS ?
       BLOCK_SYMBOLS : (data->num_symbols - offset));
     memcpy(b.symbols, data->received_symbols + offset, b.count * sizeof(rmt_symbol_word_t));
-    if (xQueueSendFromISR(self->queue_, &b, &wake) != pdTRUE) self->overflow_ = true;
+    if (xQueueSendFromISR(self->queue_, &b, &wake) != pdTRUE)
+      __atomic_fetch_add(&self->droppedItems_, b.count, __ATOMIC_RELAXED);
     offset += b.count;
   }
   return wake == pdTRUE;
@@ -131,10 +151,12 @@ bool PulseReceiver::nextRmtEdge(Edge &edge) {
   }
 }
 
-bool PulseReceiver::poll(PulsePeriod &period) {
+size_t PulseReceiver::readPeriods(PulsePeriod *periods, size_t capacity) {
+  size_t count = 0;
   Edge e;
-  while (nextRmtEdge(e)) if (consumeEdge(e, period)) return true;
-  return false;
+  while (count < capacity && nextRmtEdge(e))
+    if (consumeEdge(e, periods[count])) ++count;
+  return count;
 }
 #else
 void IRAM_ATTR PulseReceiver::onGpio(void *ctx) {
@@ -143,13 +165,16 @@ void IRAM_ATTR PulseReceiver::onGpio(void *ctx) {
   if (RX_SIGNAL_INVERTED) level = !level;
   Edge e = {esp_cpu_get_cycle_count(), static_cast<uint8_t>(level)};
   BaseType_t wake = pdFALSE;
-  if (xQueueSendFromISR(self->queue_, &e, &wake) != pdTRUE) self->overflow_ = true;
+  if (xQueueSendFromISR(self->queue_, &e, &wake) != pdTRUE)
+    __atomic_fetch_add(&self->droppedItems_, 1U, __ATOMIC_RELAXED);
   if (wake) portYIELD_FROM_ISR();
 }
 
-bool PulseReceiver::poll(PulsePeriod &period) {
+size_t PulseReceiver::readPeriods(PulsePeriod *periods, size_t capacity) {
+  size_t count = 0;
   Edge e;
-  while (xQueueReceive(queue_, &e, 0) == pdTRUE) if (consumeEdge(e, period)) return true;
-  return false;
+  while (count < capacity && xQueueReceive(queue_, &e, 0) == pdTRUE)
+    if (consumeEdge(e, periods[count])) ++count;
+  return count;
 }
 #endif

OpticalChannelTester/Receiver.h

@@ -1,6 +1,7 @@
 #pragma once
 #include <Arduino.h>
 #include <esp_idf_version.h>
+#include "Config.h"
 #include "Core.h"
 
 #if ESP_IDF_VERSION >= ESP_IDF_VERSION_VAL(5, 5, 0)
@@ -17,9 +18,11 @@ class PulseReceiver {
   bool start(uint32_t expectedHz);
   void stop();
   void resetStream();
-  bool poll(PulsePeriod &period);
+  size_t readPeriods(PulsePeriod *periods, size_t capacity);
   bool overflowed();
+  uint32_t takeDroppedItems();
   uint32_t tickHz() const;
+  uint16_t receiveChunkSymbols() const { return receiveChunkSymbols_; }
   bool highRateBackend() const {
 #if OPTICAL_USE_RMT_DMA && CONFIG_IDF_TARGET_ESP32S3
     return true;
@@ -32,12 +35,14 @@ class PulseReceiver {
   bool consumeEdge(const Edge &edge, PulsePeriod &period);
 
 #if OPTICAL_USE_RMT_DMA
-  static constexpr size_t BLOCK_SYMBOLS = 64;
+  static constexpr size_t BLOCK_SYMBOLS = RMT_MAX_RECEIVE_SYMBOLS;
   struct SymbolBlock { uint16_t count; rmt_symbol_word_t symbols[BLOCK_SYMBOLS]; };
   static bool IRAM_ATTR onRmt(rmt_channel_handle_t, const rmt_rx_done_event_data_t *, void *);
   bool nextRmtEdge(Edge &edge);
   rmt_channel_handle_t channel_ = nullptr;
-  rmt_symbol_word_t dmaBuffer_[512];
+  rmt_symbol_word_t receiveBuffer_[RMT_MAX_RECEIVE_SYMBOLS];
+  uint16_t receiveChunkSymbols_ = 0;
+  SymbolBlock isrBlock_ = {};
   SymbolBlock block_ = {};
   uint16_t blockIndex_ = 0;
   uint8_t phase_ = 0;
@@ -50,6 +55,7 @@ class PulseReceiver {
 #endif
   QueueHandle_t queue_ = nullptr;
   volatile bool overflow_ = false;
+  volatile uint32_t droppedItems_ = 0;
   bool running_ = false;
   bool haveRise_ = false, haveFall_ = false, haveRawTick_ = false;
   uint32_t lastRawTick_ = 0;

OpticalChannelTester/SettingsStore.cpp

@@ -1,5 +1,6 @@
 #include "SettingsStore.h"
 #include "Config.h"
+#include "Log.h"
 #include <Preferences.h>
 
 namespace { constexpr uint16_t SETTINGS_VERSION = 1; constexpr char NAMESPACE[] = "opt-test"; }
@@ -20,20 +21,21 @@ bool SettingsStore::valid(const Settings &s) const {
 
 bool SettingsStore::load(Settings &s) {
   Preferences prefs;
-  if (!prefs.begin(NAMESPACE, true)) { defaults(s); return false; }
+  if (!prefs.begin(NAMESPACE, true)) { defaults(s); Log::event("NVS", "open for read FAILED; defaults selected"); return false; }
   const size_t got = prefs.getBytes("settings", &s, sizeof(s));
   prefs.end();
-  if (got != sizeof(s) || !valid(s)) { defaults(s); return false; }
+  if (got != sizeof(s) || !valid(s)) { defaults(s); Log::event("NVS", "missing/corrupt settings; defaults selected"); return false; }
+  Log::event("NVS", "settings loaded and validated");
   return true;
 }
 
 bool SettingsStore::save(Settings &s) {
   s.version = SETTINGS_VERSION; s.checksum = settingsChecksum(s);
-  if (!valid(s)) return false;
+  if (!valid(s)) { Log::event("NVS", "save rejected: invalid settings"); return false; }
   Preferences prefs;
-  if (!prefs.begin(NAMESPACE, false)) return false;
+  if (!prefs.begin(NAMESPACE, false)) { Log::event("NVS", "open for write FAILED"); return false; }
   const bool ok = prefs.putBytes("settings", &s, sizeof(s)) == sizeof(s);
-  prefs.end(); return ok;
+  prefs.end(); Log::printf("NVS", "settings save %s", ok ? "OK" : "FAILED"); return ok;
 }
 
 TestParams SettingsStore::params(const Settings &s) const {
@@ -42,4 +44,3 @@ TestParams SettingsStore::params(const Settings &s) const {
     TEST_TIME_OPTIONS_MS[s.timeIndex], REPEAT_OPTIONS[s.repeatIndex],
     DUTY_OPTIONS_PCT[s.dutyIndex]};
 }
-

README.md

@@ -18,6 +18,7 @@
 - Preferences/NVS с версией структуры, checksum, проверкой индексов и восстановлением defaults;
 - работа через Serial при отсутствующем OLED;
 - безопасное выключение PWM при PASS, FAIL, ABORT и потере связи.
+- полный журнал действий в Serial с временными метками; OLED необязателен.
 
 ## Файлы
 
@@ -29,6 +30,7 @@ Arduino sketch находится в каталоге `OpticalChannelTester`:
 - `Buttons.*` — автомат двух кнопок;
 - `SettingsStore.*` — NVS;
 - `Display.*` — OLED и компактное форматирование;
+- `Log.*` — журнал действий и Serial-зеркало интерфейса;
 - `Pwm.*` — LEDC;
 - `Receiver.*` — RMT RX / совместимый fallback;
 - `Measurement.*` — строгая проверка периодов;
@@ -68,6 +70,32 @@ Arduino sketch находится в каталоге `OpticalChannelTester`:
 
 Подключите SSD1306 128×32: `VCC → 3.3 V`, `GND → GND`, `SDA/SCL` по таблице. Адрес по умолчанию `0x3C`. Если OLED не отвечает, тест продолжает работать и пишет диагностику в Serial 115200.
 
+### Работа вообще без OLED
+
+OLED можно не подключать. Откройте Serial Monitor на **115200 baud**: каждый экран всегда дублируется одной строкой вида:
+
+```text
+[      1250][UI      ] MODE: SOLO | START=RUN
+```
+
+В Serial также выводятся:
+
+- каждое распознанное нажатие START/MODE и текущее состояние автомата;
+- вход, изменение и сохранение каждого пункта меню;
+- загрузка, проверка и сохранение NVS;
+- запуск/остановка PWM и реальные параметры LEDC;
+- начало этапа, число отбрасываемых периодов и параметры измерительного окна;
+- все действия ESP-NOW, peer, session/stage/sequence, ACK и повторы;
+- статистика этапа, первый плохой период и итоговая причина завершения;
+- все строки, которые были бы показаны на OLED.
+
+Во время строгого измерительного окна отдельные импульсы намеренно не печатаются: они проверяются потоково, а итоговая статистика выводится после окна. Это предотвращает влияние Serial на точность и переполнение очереди RMT. Журнал действий включён параметрами в `Config.h`:
+
+```cpp
+constexpr bool SERIAL_ACTION_LOG = true;
+constexpr bool SERIAL_LOG_TIMESTAMPS = true;
+```
+
 ### Кнопки
 
 По умолчанию задано:
@@ -174,8 +202,8 @@ PWM_SETTLE_CYCLES / actualFrequency + TEST_TIME * REPEATS
 
 | Target | Arduino-ESP32 | Flash | RAM | Результат |
 |---|---:|---:|---:|---|
-| ESP32-C3 | 3.3.10 | 1,020,337 B (77%) | 39,460 B (12%) | PASS |
-| ESP32-S3 | 3.3.10 | 947,712 B (72%) | 48,620 B (14%) | PASS |
+| ESP32-C3 | 3.3.10 | 1,025,021 B (78%) | 45,380 B (13%) | PASS |
+| ESP32-S3 | 3.3.10 | 950,608 B (72%) | 48,620 B (14%) | PASS |
 
 Локальные unit-тесты: `core tests: PASS`, `button tests: PASS`. Они покрывают неделимый диапазон, END без дубля, ALL, границы допусков, немедленный FAIL, resolution, checksum настроек, CRC протокола и отсутствие short после long.