fix(bench): millisecond PTP epoch seeding and resilient SV session lease with diagnostic evidence

apps/arstack_studio/src/DeviceController.cpp

@@ -1364,7 +1364,7 @@ QString DeviceController::ptpConfigCommand(const QVariantMap& profile) {
     if (profile.value(QStringLiteral("benchGlobalGm")).toBool()) {
         // Studio supplies a fresh host UTC epoch. The device then uses
         // one EMAC IEEE1588 timebase for both PTP TX and SV sampling.
-        command += QStringLiteral(" 1 %1").arg(QDateTime::currentSecsSinceEpoch());
+        command += QStringLiteral(" 1 %1").arg(QDateTime::currentMSecsSinceEpoch());
     }
     return command;
 }

embedded/esp32p4_smv_injector/main/live_control.cpp

@@ -41,7 +41,12 @@ constexpr char kTag[] = "ar_smv_ctrl";
 constexpr std::array<std::string_view, 8> kChannelNames{
     "IA", "IB", "IC", "IN", "UA", "UB", "UC", "UN"};
 constexpr std::string_view kTokenDelimiters{" \t\r\n"};
-constexpr std::uint32_t kControlLeaseTimeoutMs = 2500U;
+// A 700-ms host heartbeat is coalesced through a serial command queue.
+// A 2.5-second lease caused unnecessary SV STOP during transient Windows USB
+// stalls. Allow several missed scheduling slots, but still fail CLOSED after
+// six seconds without a real device-consumed heartbeat.
+constexpr std::uint32_t kControlLeaseTimeoutMs = 6000U;
+constexpr std::uint32_t kSlowHeartbeatGapMs = 2000U;
 // Fixed-rate watchdog never stops/rearms from console heartbeat and timer
 // callback concurrently. An expired lease is detected in <=timeout+250ms.
 constexpr std::uint64_t kControlWatchdogPeriodUs = 250000ULL;
@@ -67,6 +72,8 @@ std::atomic<TaskHandle_t> g_publisher_task{nullptr};
 std::atomic<bool> g_control_heartbeat_seen{false};
 std::atomic<bool> g_control_lease_active{false};
 std::atomic<std::uint32_t> g_last_heartbeat_ms{0U};
+std::atomic<std::uint32_t> g_max_heartbeat_gap_ms{0U};
+std::atomic<std::uint32_t> g_slow_heartbeat_events{0U};
 std::atomic<bool> g_control_watchdog_ready{false};
 std::atomic<SvStopCause> g_last_sv_stop_cause{SvStopCause::none};
 std::atomic<std::uint32_t> g_sv_stop_seq{0U};
@@ -155,7 +162,16 @@ void control_lease_timer_callback(void*) noexcept {
 
 void record_control_heartbeat() noexcept {
     portENTER_CRITICAL(&g_control_lease_mux);
-    g_last_heartbeat_ms.store(monotonic_ms(), std::memory_order_release);
+    const std::uint32_t now_ms = monotonic_ms();
+    if (g_control_heartbeat_seen.load(std::memory_order_relaxed)) {
+        const std::uint32_t gap_ms = now_ms -
+            g_last_heartbeat_ms.load(std::memory_order_relaxed);
+        if (gap_ms > g_max_heartbeat_gap_ms.load(std::memory_order_relaxed))
+            g_max_heartbeat_gap_ms.store(gap_ms, std::memory_order_relaxed);
+        if (gap_ms > kSlowHeartbeatGapMs)
+            g_slow_heartbeat_events.fetch_add(1U, std::memory_order_relaxed);
+    }
+    g_last_heartbeat_ms.store(now_ms, std::memory_order_release);
     g_control_heartbeat_seen.store(true, std::memory_order_release);
     portEXIT_CRITICAL(&g_control_lease_mux);
     // No esp_timer_stop/start from this control task, and no lease renewal
@@ -430,15 +446,30 @@ void handle_ptp_command(char* save) noexcept {
             }
         }
         bool bench_global = false;
-        std::uint32_t utc_epoch = 0U;
+        std::uint32_t utc_epoch_seconds = 0U;
+        std::uint16_t utc_epoch_millis = 0U;
         char* bench_text = strtok_r(nullptr, kTokenDelimiters.data(), &save);
         if (bench_text != nullptr) {
             std::uint32_t bench = 0U;
+            std::uint64_t utc_input = 0ULL;
             if (!parse_u32(bench_text, bench) || bench > 1U ||
-                !parse_u32(strtok_r(nullptr, kTokenDelimiters.data(), &save), utc_epoch)) {
+                !parse_u64(strtok_r(nullptr, kTokenDelimiters.data(), &save), utc_input, 10)) {
                 ESP_LOGE(kTag, "PTP configuration rejected: expected bench mode and UTC epoch");
                 return;
             }
+            // Accept both legacy Unix seconds and new Unix milliseconds.
+            // Full milliseconds avoid the ~0..999ms truncation caused by
+            // QDateTime::currentSecsSinceEpoch on the Windows host.
+            const bool epoch_in_milliseconds = utc_input >= 100000000000ULL;
+            const std::uint64_t seconds = epoch_in_milliseconds
+                ? utc_input / 1000ULL : utc_input;
+            if (seconds > UINT32_MAX || seconds < 1577836800ULL) {
+                ESP_LOGE(kTag, "PTP configuration rejected: UTC epoch outside supported range");
+                return;
+            }
+            utc_epoch_seconds = static_cast<std::uint32_t>(seconds);
+            utc_epoch_millis = epoch_in_milliseconds
+                ? static_cast<std::uint16_t>(utc_input % 1000ULL) : 0U;
             bench_global = bench != 0U;
         }
         if (has_extra_token(&save) || values[0] > 255U || values[1] > 15U || values[2] > 1U ||
@@ -461,17 +492,19 @@ void handle_ptp_command(char* save) noexcept {
         config.sync_interval_ms = values[6];
         config.respond_to_peer_delay = values[7] != 0U;
         config.bench_global_gm = bench_global;
-        config.bench_utc_epoch_seconds = bench_global ? utc_epoch : 0U;
+        config.bench_utc_epoch_seconds = bench_global ? utc_epoch_seconds : 0U;
+        config.bench_utc_epoch_millisecond = bench_global ? utc_epoch_millis : 0U;
         config.bench_epoch_received_mono_us = bench_global ? esp_timer_get_time() : 0LL;
         if (!ar_ptp_lab_configure(&config)) {
             ESP_LOGE(kTag, "PTP configuration rejected: reason=%s",
                      ar_ptp_lab_last_config_error());
             return;
         }
         ESP_LOGI(kTag, "PTP configuration accepted");
-        ESP_LOGI(kTag, "PTP GM emulation=%u UTC_seed=%lu",
+        ESP_LOGI(kTag, "PTP GM emulation=%u UTC_seed=%lu.%03u",
                  config.bench_global_gm ? 1U : 0U,
-                 static_cast<unsigned long>(config.bench_utc_epoch_seconds));
+                 static_cast<unsigned long>(config.bench_utc_epoch_seconds),
+                 static_cast<unsigned>(config.bench_utc_epoch_millisecond));
         print_ptp_state();
         return;
     }
@@ -493,7 +526,8 @@ void print_state() noexcept {
     const auto stop_reason = g_last_sv_stop_cause.load(std::memory_order_acquire);
     ESP_LOGI(kTag,
              "SVLIFE state=%s stop_cause=%s stop_seq=%lu stop_uptime_ms=%lu "
-             "stop_hb_age_ms=%lu hb_age_ms=%lu hb_seen=%u lease_ms=%lu watchdog=%u",
+             "stop_hb_age_ms=%lu hb_age_ms=%lu hb_seen=%u lease_ms=%lu watchdog=%u "
+             "hb_max_gap_ms=%lu hb_slow_events=%lu",
              g_running.load(std::memory_order_acquire) ? "RUNNING" : "STOPPED",
              sv_stop_cause_name(stop_reason),
              static_cast<unsigned long>(g_sv_stop_seq.load(std::memory_order_acquire)),
@@ -502,7 +536,11 @@ void print_state() noexcept {
              static_cast<unsigned long>(hb_seen ? now_ms - hb_last : 0U),
              hb_seen ? 1U : 0U,
              static_cast<unsigned long>(kControlLeaseTimeoutMs),
-             g_control_watchdog_ready.load(std::memory_order_acquire) ? 1U : 0U);
+             g_control_watchdog_ready.load(std::memory_order_acquire) ? 1U : 0U,
+             static_cast<unsigned long>(
+                 g_max_heartbeat_gap_ms.load(std::memory_order_acquire)),
+             static_cast<unsigned long>(
+                 g_slow_heartbeat_events.load(std::memory_order_acquire)));
     for (std::size_t index = 0U; index < state.channels.size(); ++index) {
         const auto& channel = state.channels[index];
         ESP_LOGI(kTag,
@@ -860,6 +898,8 @@ void live_control_initialize(
     g_running.store(false, std::memory_order_release);
     g_start_request.store(false, std::memory_order_release);
     clear_control_session();
+    g_max_heartbeat_gap_ms.store(0U, std::memory_order_release);
+    g_slow_heartbeat_events.store(0U, std::memory_order_release);
     g_last_sv_stop_cause.store(SvStopCause::none, std::memory_order_release);
     g_sv_stop_seq.store(0U, std::memory_order_release);
     g_last_sv_stop_ms.store(0U, std::memory_order_release);

embedded/esp32p4_smv_injector/main/ptp_lab_task.cpp

@@ -197,6 +197,7 @@ void fill_kconfig_defaults(ar_ptp_lab_config_t& config) noexcept {
     config.current_utc_offset = static_cast<std::int16_t>(CONFIG_AR_PTP_CURRENT_UTC_OFFSET);
     config.bench_global_gm = false;
     config.bench_utc_epoch_seconds = 0U;
+    config.bench_utc_epoch_millisecond = 0U;
     config.bench_epoch_received_mono_us = 0LL;
 
     const std::string configured_identity{CONFIG_AR_PTP_CLOCK_IDENTITY};
@@ -288,6 +289,7 @@ void fill_kconfig_defaults(ar_ptp_lab_config_t& config) noexcept {
     // (seed_hardware_clock), not during a prior PTPROLE change.
     if (config.role == AR_PTP_ROLE_LAB_SOURCE && config.bench_global_gm &&
         (config.bench_utc_epoch_seconds < 1577836800U ||
+         config.bench_utc_epoch_millisecond >= 1000U ||
          config.bench_epoch_received_mono_us <= 0LL)) {
         error = "BENCH GM requires a Studio UTC epoch";
         return false;
@@ -421,16 +423,19 @@ void disable_hardware_ptp(const esp_eth_handle_t eth_handle) noexcept {
         ? static_cast<std::uint64_t>(
               now_mono_us - config.bench_epoch_received_mono_us)
         : 0ULL;
+    const std::uint64_t relative_epoch_us = elapsed_us +
+        (bench ? static_cast<std::uint64_t>(
+            config.bench_utc_epoch_millisecond) * 1000ULL : 0ULL);
     const std::int64_t utc_seconds = bench
         ? static_cast<std::int64_t>(config.bench_utc_epoch_seconds) +
-              static_cast<std::int64_t>(elapsed_us / 1000000ULL)
+              static_cast<std::int64_t>(relative_epoch_us / 1000000ULL)
         : static_cast<std::int64_t>(std::time(nullptr));
     const auto tai_seconds = ar::iec61850::time_sync::try_seed_ptp_tai_seconds(
         utc_seconds, config.current_utc_offset);
     if (tai_seconds.has_value()) {
         initial_time.seconds = *tai_seconds;
         initial_time.nanoseconds = bench
-            ? static_cast<std::uint32_t>((elapsed_us % 1000000ULL) * 1000ULL)
+            ? static_cast<std::uint32_t>((relative_epoch_us % 1000000ULL) * 1000ULL)
             : 0U;
     }
     const auto result = esp_eth_ioctl(

embedded/esp32p4_smv_injector/main/ptp_lab_task.hpp

@@ -50,6 +50,9 @@ typedef struct ar_ptp_lab_config_t {
     // The PC supplies an approximate UTC epoch, not a physical GPS input.
     bool bench_global_gm;
     uint32_t bench_utc_epoch_seconds;
+    // Millisecond fraction of the same UTC second. Sending seconds alone
+    // previously introduced up to 999 ms of avoidable clock seed error.
+    uint16_t bench_utc_epoch_millisecond;
     int64_t bench_epoch_received_mono_us;
 
     // P2 measured discipline thresholds. These are used only in TIME_RECEIVER.