Add dexter underflow thread, still problematic

4 files changed, 73 insertions, 36 deletions

diff --git a/src/DabMod.cpp b/src/DabMod.cpp
index 5a4da9a..45f4d0a 100644
--- a/src/DabMod.cpp
+++ b/src/DabMod.cpp
@@ -493,8 +493,7 @@ int launch_modulator(int argc, char* argv[])
                 break;
         }
 
-        etiLog.level(info) << m.framecount << " DAB frames encoded";
-        etiLog.level(info) << ((float)m.framecount * 0.024f) << " seconds encoded";
+        etiLog.level(info) << m.framecount << " DAB frames, " << ((float)m.framecount * 0.024f) << " seconds encoded";
     }
 
     etiLog.level(info) << "Terminating";
diff --git a/src/output/Dexter.cpp b/src/output/Dexter.cpp
index ad4711c..5904824 100644
--- a/src/output/Dexter.cpp
+++ b/src/output/Dexter.cpp
@@ -188,10 +188,21 @@ Dexter::Dexter(SDRDeviceConfig& config) :
     if (!m_buffer) {
         throw std::runtime_error("Dexter: Cannot create IIO buffer.");
     }
+
+#warning "TODO underflow thread"
+    /* Disabled because it still provokes failed to push buffer Unknown error -110
+    m_running = true;
+    m_underflow_read_thread = std::thread(&Dexter::underflow_read_process, this);
+    */
 }
 
 Dexter::~Dexter()
 {
+    m_running = false;
+    if (m_underflow_read_thread.joinable()) {
+        m_underflow_read_thread.join();
+    }
+
     if (m_ctx) {
         if (m_dexter_dsp_tx) {
             iio_device_attr_write_longlong(m_dexter_dsp_tx, "gain0", 0);
@@ -271,7 +282,10 @@ double Dexter::get_bandwidth(void) const
 SDRDevice::RunStatistics Dexter::get_run_statistics(void) const
 {
     RunStatistics rs;
-    rs.num_underruns = underflows;
+    {
+        std::unique_lock<std::mutex> lock(m_underflows_mutex);
+        rs.num_underruns = underflows;
+    }
     rs.num_overruns = 0;
     rs.num_late_packets = num_late;
     rs.num_frames_modulated = num_frames_modulated;
@@ -374,19 +388,18 @@ void Dexter::transmit_frame(const struct FrameData& frame)
             etiLog.level(error) << "Failed to get dexter_dsp_tx.pps_clks: " << get_iio_error(r);
         }
 
-        /*
+        const double margin = (double)((int64_t)frame_ts_clocks - pps_clks) / DSP_CLOCK;
+
         etiLog.level(debug) << "Dexter: TS CLK " <<
             ((int64_t)frame.ts.timestamp_sec - (int64_t)m_utc_seconds_at_startup) * DSP_CLOCK << " + " <<
             m_clock_count_at_startup << " + " <<
             (uint64_t)frame.ts.timestamp_pps * TIMESTAMP_PPS_PER_DSP_CLOCKS << " = " <<
             frame_ts_clocks << " DELTA " <<
-            frame_ts_clocks << " - " << pps_clks << " = " <<
-            (double)((int64_t)frame_ts_clocks - pps_clks) / DSP_CLOCK;
-        */
+            frame_ts_clocks << " - " << pps_clks << " = " << margin;
 
-        // Ensure we hand the frame over to HW at least 0.1s before timestamp
-        if (((int64_t)frame_ts_clocks - pps_clks) < (int64_t)DSP_CLOCK / 10) {
-            etiLog.level(warn) << "Skip frame short margin";
+        // Ensure we hand the frame over to HW at least 0.2s before timestamp
+        if (margin < 0.2) {
+            etiLog.level(warn) << "Skip frame short margin " << margin;
             num_late++;
             return;
         }
@@ -404,13 +417,6 @@ void Dexter::transmit_frame(const struct FrameData& frame)
     if (m_require_timestamp_refresh) {
         etiLog.level(debug) << "TIMESTAMP_STATE WAIT_FOR_UNDERRUN";
         timestamp_state = timestamp_state_t::WAIT_FOR_UNDERRUN;
-        long long attr_value = 0;
-        int r = 0;
-
-        if ((r = iio_device_attr_read_longlong(m_dexter_dsp_tx, "buffer_underflows0", &attr_value)) == 0) {
-            underflows = attr_value;
-            etiLog.level(debug) << "UNDERFLOWS CAPTURE " << underflows;
-        }
     }
 
     // DabMod::launch_modulator ensures we get int16_t IQ here
@@ -424,33 +430,55 @@ void Dexter::transmit_frame(const struct FrameData& frame)
             memcpy(iio_buffer_start(m_buffer), frame.buf.data() + (i * buflen), buflen);
             ssize_t pushed = iio_buffer_push(m_buffer);
             if (pushed < 0) {
-                etiLog.level(error) << "Dexter: failed to push buffer " << get_iio_error(pushed);
+                etiLog.level(error) << "Dexter: failed to push buffer " << get_iio_error(pushed) <<
+                    " after " << num_buffers_pushed << " bufs";
+                num_buffers_pushed = 0;
                 etiLog.level(debug) << "TIMESTAMP_STATE REQUIRES_SET";
                 timestamp_state = timestamp_state_t::REQUIRES_SET;
+                break;
             }
+            num_buffers_pushed++;
         }
         num_frames_modulated++;
     }
 
-#warning "We should update underflows all the time"
-    if (timestamp_state == timestamp_state_t::WAIT_FOR_UNDERRUN) {
+    {
+        std::unique_lock<std::mutex> lock(m_underflows_mutex);
+        size_t u = underflows;
+        lock.unlock();
+
+        if (u != 0 and u != prev_underflows) {
+            etiLog.level(warn) << "Dexter: underflow! " << prev_underflows << " -> " << u;
+            if (timestamp_state == timestamp_state_t::WAIT_FOR_UNDERRUN) {
+                etiLog.level(debug) << "TIMESTAMP_STATE REQUIRES_SET";
+                timestamp_state = timestamp_state_t::REQUIRES_SET;
+            }
+        }
+
+        prev_underflows = u;
+    }
+}
+
+void Dexter::underflow_read_process()
+{
+    set_thread_name("dexter_underflow");
+
+    while (m_running) {
         long long attr_value = 0;
         int r = 0;
 
         if ((r = iio_device_attr_read_longlong(m_dexter_dsp_tx, "buffer_underflows0", &attr_value)) == 0) {
             size_t underflows_new = attr_value;
-            etiLog.level(debug) << "UNDERFLOWS COMPARE " << underflows_new;
 
+            std::unique_lock<std::mutex> lock(m_underflows_mutex);
+            etiLog.level(debug) << "UNDERFLOWS INC BY " << attr_value - (ssize_t)underflows;
             if (underflows_new != underflows and attr_value != 0) {
-                etiLog.level(warn) << "Dexter: underflow! " << underflows << " -> " << underflows_new;
                 underflows = underflows_new;
-                if (timestamp_state == timestamp_state_t::WAIT_FOR_UNDERRUN) {
-                    etiLog.level(debug) << "TIMESTAMP_STATE REQUIRES_SET";
-                    timestamp_state = timestamp_state_t::REQUIRES_SET;
-                }
             }
         }
+        this_thread::sleep_for(chrono::seconds(1));
     }
+    m_running = false;
 }
 
 } // namespace Output
diff --git a/src/output/Dexter.h b/src/output/Dexter.h
index 3e9c34f..a3c827b 100644
--- a/src/output/Dexter.h
+++ b/src/output/Dexter.h
@@ -40,6 +40,8 @@ DESCRIPTION:
 #include <string>
 #include <memory>
 #include <ctime>
+#include <mutex>
+#include <thread>
 
 #include "output/SDR.h"
 #include "ModPlugin.h"
@@ -54,20 +56,20 @@ class Dexter : public Output::SDRDevice
         Dexter(SDRDeviceConfig& config);
         Dexter(const Dexter& other) = delete;
         Dexter& operator=(const Dexter& other) = delete;
-        ~Dexter();
+        virtual ~Dexter();
 
         virtual void tune(double lo_offset, double frequency) override;
         virtual double get_tx_freq(void) const override;
         virtual void set_txgain(double txgain) override;
-        virtual double get_txgain(void) const override;
+        virtual double get_txgain() const override;
         virtual void set_bandwidth(double bandwidth) override;
-        virtual double get_bandwidth(void) const override;
+        virtual double get_bandwidth() const override;
         virtual void transmit_frame(const struct FrameData& frame) override;
-        virtual RunStatistics get_run_statistics(void) const override;
-        virtual double get_real_secs(void) const override;
+        virtual RunStatistics get_run_statistics() const override;
+        virtual double get_real_secs() const override;
 
         virtual void set_rxgain(double rxgain) override;
-        virtual double get_rxgain(void) const override;
+        virtual double get_rxgain() const override;
         virtual size_t receive_frame(
                 complexf *buf,
                 size_t num_samples,
@@ -75,10 +77,10 @@ class Dexter : public Output::SDRDevice
                 double timeout_secs) override;
 
         // Return true if GPS and reference clock inputs are ok
-        virtual bool is_clk_source_ok(void) const override;
-        virtual const char* device_name(void) const override;
+        virtual bool is_clk_source_ok() const override;
+        virtual const char* device_name() const override;
 
-        virtual double get_temperature(void) const override;
+        virtual double get_temperature() const override;
 
     private:
         SDRDeviceConfig& m_conf;
@@ -90,10 +92,19 @@ class Dexter : public Output::SDRDevice
         struct iio_channel* m_tx_channel = nullptr;
         struct iio_buffer *m_buffer = nullptr;
 
+        /* Underflows are counted in a separate thread */
+        std::atomic<bool> m_running = ATOMIC_VAR_INIT(false);
+        std::thread m_underflow_read_thread;
+        void underflow_read_process();
+        mutable std::mutex m_underflows_mutex;
         size_t underflows = 0;
+
+        size_t prev_underflows = 0;
         size_t num_late = 0;
         size_t num_frames_modulated = 0;
 
+        size_t num_buffers_pushed = 0;
+
         uint64_t m_utc_seconds_at_startup;
         uint64_t m_clock_count_at_startup = 0;
         uint64_t m_clock_count_frame = 0;
diff --git a/src/output/SDR.cpp b/src/output/SDR.cpp
index ae09acd..2b6700f 100644
--- a/src/output/SDR.cpp
+++ b/src/output/SDR.cpp
@@ -106,7 +106,6 @@ SDR::~SDR()
 
 void SDR::set_sample_size(size_t size)
 {
-    etiLog.level(debug) << "Setting sample size to " << size;
     m_size = size;
 }