Millisecond time and backoff fix, the third time is the charm?

trunk-recorder/call.h

@@ -9,6 +9,7 @@
 #include <string>
 #include <sys/time.h>
 #include <vector>
+#include <cstdint>
 
 class Recorder;
 class System;
@@ -66,6 +67,7 @@ class Call {
   virtual void set_is_analog(bool a) = 0;
   virtual const char *get_xor_mask() = 0;
   virtual time_t get_start_time() = 0;
+  virtual std::int64_t get_start_time_ms() = 0;
   virtual bool is_conventional() = 0;
   virtual void set_encrypted(bool m) = 0;
   virtual bool get_encrypted() = 0;

trunk-recorder/call_conventional.cc

@@ -3,6 +3,7 @@
 #include "formatter.h"
 #include "recorders/recorder.h"
 #include <boost/algorithm/string.hpp>
+#include <chrono>
 
 Call_conventional::Call_conventional(long t, double f, System *s, Config c, double squelch_db, bool signal_detection) : Call_impl(t, f, s, c) {
   this->squelch_db = squelch_db;
@@ -16,8 +17,13 @@ void Call_conventional::restart_call() {
   signal = DB_UNSET;
   noise = DB_UNSET;
   curr_src_id = -1;
-  start_time = time(NULL);
-  stop_time = time(NULL);
+
+  auto now = std::chrono::system_clock::now();
+  start_time    = std::chrono::system_clock::to_time_t(now);
+  start_time_ms = std::chrono::duration_cast<std::chrono::milliseconds>(now.time_since_epoch()).count();
+  stop_time     = start_time;
+  stop_time_ms  = start_time_ms;
+
   last_update = time(NULL);
   state = RECORDING;
   debug_recording = false;
@@ -29,9 +35,13 @@ void Call_conventional::restart_call() {
   recorder->start(this);
 }
 
+// derive start from stop − final_length:
 time_t Call_conventional::get_start_time() {
   // Fixes https://github.com/robotastic/trunk-recorder/issues/103#issuecomment-284825841
-  return start_time = stop_time - final_length;
+  start_time = stop_time - final_length;
+  // keep ms in sync (rounded):
+  start_time_ms = stop_time_ms - static_cast<std::int64_t>(std::llround(final_length * 1000.0));
+  return start_time;
 }
 
 void Call_conventional::set_recorder(Recorder *r) {
@@ -40,7 +50,9 @@ void Call_conventional::set_recorder(Recorder *r) {
 }
 
 void Call_conventional::recording_started() {
-  start_time = time(NULL);
+  auto now = std::chrono::system_clock::now();
+  start_time    = std::chrono::system_clock::to_time_t(now);
+  start_time_ms = std::chrono::duration_cast<std::chrono::milliseconds>(now.time_since_epoch()).count();
 }
 
 double Call_conventional::get_squelch_db() {

trunk-recorder/call_impl.cc

@@ -8,6 +8,7 @@
 #include <boost/algorithm/string.hpp>
 #include <signal.h>
 #include <stdio.h>
+#include <chrono>
 
 std::string Call_impl::get_capture_dir() {
   return this->config.capture_dir;
@@ -41,6 +42,11 @@ Call_impl::Call_impl(long t, double f, System *s, Config c) {
   sys = s;
   start_time = time(NULL);
   stop_time = time(NULL);
+  start_time_ms =
+        std::chrono::duration_cast<std::chrono::milliseconds>(
+            std::chrono::system_clock::now().time_since_epoch()
+        ).count();
+  stop_time_ms = 0;
   last_update = time(NULL);
   state = MONITORING;
   monitoringState = UNSPECIFIED;
@@ -74,6 +80,11 @@ Call_impl::Call_impl(TrunkMessage message, System *s, Config c) {
   sys = s;
   start_time = time(NULL);
   stop_time = time(NULL);
+  start_time_ms =
+        std::chrono::duration_cast<std::chrono::milliseconds>(
+            std::chrono::system_clock::now().time_since_epoch()
+        ).count();
+  stop_time_ms = 0;
   last_update = time(NULL);
   state = MONITORING;
   monitoringState = UNSPECIFIED;
@@ -123,6 +134,10 @@ void Call_impl::conclude_call() {
 
   // BOOST_LOG_TRIVIAL(info) << "conclude_call()";
   stop_time = time(NULL);
+  stop_time_ms =
+        std::chrono::duration_cast<std::chrono::milliseconds>(
+            std::chrono::system_clock::now().time_since_epoch()
+        ).count();
 
   if (state == RECORDING || (state == MONITORING && monitoringState == SUPERSEDED)) {
     if (!recorder) {
@@ -213,6 +228,21 @@ double Call_impl::get_current_length() {
   }
 }
 
+std::int64_t Call_impl::get_start_time_ms() {
+  // Prefer the earliest transmission start (true playable start)
+  if (!transmission_list.empty()) {
+    std::int64_t best = 0;
+    for (const auto& t : transmission_list) {
+      if (t.start_time_ms > 0 && (best == 0 || t.start_time_ms < best)) {
+        best = t.start_time_ms;
+      }
+    }
+    if (best > 0) return best;
+  }
+  // Fallback: call creation time in ms
+  return start_time_ms;
+}
+
 System *Call_impl::get_system() {
   return sys;
 }
@@ -490,6 +520,8 @@ boost::property_tree::ptree Call_impl::get_stats() {
   call_node.put("duplex", this->get_duplex());
   call_node.put("startTime", this->get_start_time());
   call_node.put("stopTime", this->get_stop_time());
+  call_node.put("startTimeMs", this->get_start_time_ms());
+  call_node.put("stopTimeMs",  this->stop_time_ms);
   call_node.put("srcId", this->get_current_source_id());
 
   Recorder *recorder = this->get_recorder();

trunk-recorder/call_impl.h

@@ -68,6 +68,7 @@ class Call_impl : public Call {
   void set_is_analog(bool a);
   const char *get_xor_mask();
   virtual time_t get_start_time() { return start_time; }
+  virtual std::int64_t get_start_time_ms();
   bool is_conventional() { return false; }
   void set_encrypted(bool m);
   bool get_encrypted();
@@ -114,6 +115,8 @@ class Call_impl : public Call {
   int idle_count;
   time_t stop_time;
   time_t start_time;
+  std::int64_t start_time_ms;
+  std::int64_t stop_time_ms;
   bool debug_recording;
   bool sigmf_recording;
   bool was_update;

trunk-recorder/global_structs.h

@@ -1,5 +1,6 @@
 #ifndef GLOBAL_STRUCTS_H
 #define GLOBAL_STRUCTS_H
+#include <cstdint>
 #include <ctime>
 #include <string>
 #include <vector>
@@ -11,6 +12,8 @@ struct Transmission {
   long source;
   long start_time;
   long stop_time;
+  std::int64_t start_time_ms;
+  std::int64_t stop_time_ms;
   long sample_count;
   long spike_count;
   long error_count;
@@ -105,6 +108,8 @@ struct Call_Data_t {
   double noise;
   long start_time;
   long stop_time;
+  std::int64_t start_time_ms;
+  std::int64_t stop_time_ms;
   long error_count;
   long spike_count;
   bool encrypted;
@@ -128,6 +133,7 @@ struct Call_Data_t {
 
   int tdma_slot;
   double length;
+  std::int64_t call_length_ms;
   bool phase2_tdma;
 
   std::vector<Call_Source> transmission_source_list;

trunk-recorder/gr_blocks/transmission_sink.cc

@@ -33,6 +33,7 @@
 #include <gnuradio/thread/thread.h>
 #include <stdexcept>
 #include <stdio.h>
+#include <chrono>
 
 // win32 (mingw/msvc) specific
 #ifdef HAVE_IO_H
@@ -78,24 +79,56 @@ transmission_sink::transmission_sink(int n_channels, unsigned int sample_rate, i
 }
 
 void transmission_sink::create_filename() {
-  time_t work_start_time = d_start_time;
-  std::stringstream temp_path_stream;
-  // Found some good advice on Streams and Strings here: https://blog.sensecodons.com/2013/04/dont-let-stdstringstreamstrcstr-happen.html
-
-  temp_path_stream << d_current_call_temp_dir << "/" << d_current_call_short_name;
-  std::string temp_path_string = temp_path_stream.str();
-  boost::filesystem::create_directories(temp_path_string);
+  using std::ostringstream;
+  using std::setw;
+  using std::setfill;
+
+  // <temp>/<short_name>
+  boost::filesystem::path dir =
+      boost::filesystem::path(d_current_call_temp_dir) / d_current_call_short_name;
+
+  boost::system::error_code ec;
+  boost::filesystem::create_directories(dir, ec);
+  if (ec) {
+    BOOST_LOG_TRIVIAL(error) << "create_directories failed for " << dir.string()
+                             << " : " << ec.message();
+  }
 
-  int nchars;
+  // Seconds.milliseconds from d_start_time_ms
+  const long long start_ms = static_cast<long long>(d_start_time_ms);
+  const long long sec     = start_ms / 1000;
+  const int       milli   = static_cast<int>(start_ms % 1000);
+
+  // Normalize frequency to integer
+  const long long freq_i  = static_cast<long long>(std::llround(d_current_call_freq));
+
+  auto make_stem = [&](int suffix) {
+    ostringstream ts;
+    ts << sec << '.' << setw(3) << setfill('0') << milli;   // e.g. 1718145678.042
+
+    ostringstream oss;
+    oss << d_current_call_talkgroup << "-" << ts.str() << "_" << freq_i;
+    if (d_slot != -1) oss << "." << d_slot;
+    if (suffix > 0)    oss << "-" << suffix;                // collision suffix
+    oss << ".wav";
+    return oss.str();
+  };
+
+  boost::filesystem::path candidate = dir / make_stem(0);
+  for (int i = 1; boost::filesystem::exists(candidate) && i <= 99; ++i) {
+    candidate = dir / make_stem(i);
+  }
 
-  if (d_slot == -1) {
-    nchars = snprintf(current_filename, 255, "%s/%ld-%ld_%.0f.wav", temp_path_string.c_str(), d_current_call_talkgroup, work_start_time, d_current_call_freq);
+  const std::string cand_str = candidate.string();
+  const size_t cap = sizeof(current_filename);
+  if (cand_str.size() >= cap) {
+    BOOST_LOG_TRIVIAL(error)
+        << "Call: Path longer than buffer (" << cap
+        << ") — truncating filename: " << cand_str;
+    std::snprintf(current_filename, cap, "%.*s",
+                  static_cast<int>(cap - 1), cand_str.c_str());
   } else {
-    // this is for the case when it is a P25P2 TDMA or DMR recorder and 2 wav files are created, the slot is needed to keep them separate.
-    nchars = snprintf(current_filename, 255, "%s/%ld-%ld_%.0f.%d.wav", temp_path_string.c_str(), d_current_call_talkgroup, work_start_time, d_current_call_freq, d_slot);
-  }
-  if (nchars >= 255) {
-    BOOST_LOG_TRIVIAL(error) << "Call: Path longer than 255 charecters";
+    std::snprintf(current_filename, cap, "%s", cand_str.c_str());
   }
 }
 
@@ -228,15 +261,27 @@ void transmission_sink::end_transmission() {
     } else {
       BOOST_LOG_TRIVIAL(error) << "Ending transmission, sample_count is greater than 0 but d_fp is null" << std::endl;
     }
-    // if an Transmission has ended, send it to Call.
+
+    const std::int64_t dur_ms = (d_nchans > 0)
+        ? (std::int64_t)std::llround(1000.0 *
+           (double)d_sample_count / ((double)d_sample_rate * (double)d_nchans))
+        : 0;
+
+    // Assign canonical stop time from sample count
+    d_stop_time_ms = d_start_time_ms + dur_ms;
+    d_stop_time    = static_cast<time_t>(d_stop_time_ms / 1000);
+
+    // Build Transmission using the canonical fields
     Transmission transmission;
-    transmission.source = curr_src_id;      // Source ID for the Call
-    transmission.start_time = d_start_time; // Start time of the Call
-    transmission.stop_time = d_stop_time;   // when the Call eneded
-    transmission.sample_count = d_sample_count;
-    transmission.spike_count = d_spike_count;
-    transmission.error_count = d_error_count;
-    transmission.length = length_in_seconds(); // length in seconds
+    transmission.source        = curr_src_id;
+    transmission.start_time    = d_start_time;
+    transmission.stop_time     = d_stop_time;
+    transmission.start_time_ms = d_start_time_ms;
+    transmission.stop_time_ms  = d_stop_time_ms;
+    transmission.sample_count  = d_sample_count;
+    transmission.spike_count   = d_spike_count;
+    transmission.error_count   = d_error_count;
+    transmission.length        = length_in_seconds();
     d_prior_transmission_length = d_prior_transmission_length + transmission.length;
     strcpy(transmission.filename, current_filename); // Copy the filename
     this->add_transmission(transmission);
@@ -499,12 +544,10 @@ int transmission_sink::dowork(int noutput_items, gr_vector_const_void_star &inpu
       close_wav(false);
     }
 
-    time_t current_time = time(NULL);
-    if (current_time == d_start_time) {
-      d_start_time = current_time + 1;
-    } else {
-      d_start_time = current_time;
-    }
+    auto now_sys = std::chrono::system_clock::now();
+    d_start_time_ms = std::chrono::duration_cast<std::chrono::milliseconds>(
+      now_sys.time_since_epoch()).count();
+    d_start_time = static_cast<time_t>(d_start_time_ms / 1000);
 
     // create a new filename, based on the current time and source.
     create_filename();
@@ -548,7 +591,6 @@ int transmission_sink::dowork(int noutput_items, gr_vector_const_void_star &inpu
     }
   }
 
-  d_stop_time = time(NULL);
   d_last_write_time = std::chrono::steady_clock::now();
 
   if (nwritten < noutput_items) {
@@ -587,7 +629,7 @@ double transmission_sink::total_length_in_seconds() {
 }
 
 double transmission_sink::length_in_seconds() {
-  return (double)d_sample_count / (double)d_sample_rate;
+  return d_nchans > 0 ? (double)d_sample_count / ((double)d_sample_rate * (double)d_nchans) : 0.0;
 }
 
 void transmission_sink::do_update() {}

trunk-recorder/gr_blocks/transmission_sink.h

@@ -32,6 +32,7 @@
 #include <boost/log/trivial.hpp>
 #include <gnuradio/blocks/api.h>
 #include <gnuradio/sync_block.h>
+#include <chrono>
 
 class Call;
 struct Transmission;
@@ -52,6 +53,8 @@ class BLOCKS_API transmission_sink : virtual public sync_block {
   bool d_termination_flag;
   time_t d_start_time;
   time_t d_stop_time;
+  std::int64_t d_start_time_ms;
+  std::int64_t d_stop_time_ms;
   std::chrono::time_point<std::chrono::steady_clock> d_last_write_time;
   long d_spike_count;
   long d_error_count;
@@ -133,6 +136,8 @@ class BLOCKS_API transmission_sink : virtual public sync_block {
   unsigned int sample_rate();
   double total_length_in_seconds();
   double length_in_seconds();
+  std::int64_t get_start_time_ms() const { return d_start_time_ms; }
+  std::int64_t get_stop_time_ms()  const { return d_stop_time_ms;  }
   Call_Source *get_source_list();
   int get_source_count();
   virtual int work(int noutput_items,

trunk-recorder/monitor_systems.cc

@@ -1,4 +1,5 @@
 #include "monitor_systems.h"
+#include <chrono>
 using namespace std;
 
 volatile sig_atomic_t exit_flag = 0;