Improve robustness in RF Overflow (#1124)

* Use task id to track old background tasks in RA procedure

* Improve robustness against RF overflow in PHY

* Increase SNR out-of-sync threshold

* Do not change frequency if it's the same

* Increase sync priority

* Increase time to start receiving to reduce input buffer occupation

* Use scoped lock in sf_worker

lib/include/srslte/radio/radio.h

@@ -223,6 +223,9 @@ private:
   uint32_t           nof_channels       = 0;
   uint32_t           nof_carriers       = 0;
 
+  std::vector<double> cur_tx_freqs = {};
+  std::vector<double> cur_rx_freqs = {};
+
   // Define default values for known radios
   constexpr static double uhd_default_tx_adv_samples    = 98;
   constexpr static double uhd_default_tx_adv_offset_sec = 4 * 1e-6;

lib/src/phy/rf/rf_uhd_imp.c

@@ -403,7 +403,7 @@ int rf_uhd_start_rx_stream(void* h, bool now)
   uhd_stream_cmd_t stream_cmd = {.stream_mode = UHD_STREAM_MODE_START_CONTINUOUS, .stream_now = now};
   if (!now) {
     uhd_usrp_get_time_now(handler->usrp, 0, &stream_cmd.time_spec_full_secs, &stream_cmd.time_spec_frac_secs);
-    stream_cmd.time_spec_frac_secs += 0.2;
+    stream_cmd.time_spec_frac_secs += 0.5;
     if (stream_cmd.time_spec_frac_secs > 1) {
       stream_cmd.time_spec_frac_secs -= 1;
       stream_cmd.time_spec_full_secs += 1;

lib/src/radio/radio.cc

@@ -86,6 +86,9 @@ int radio::init(const rf_args_t& args, phy_interface_radio* phy_)
   nof_antennas = args.nof_antennas;
   nof_carriers = args.nof_carriers;
 
+  cur_tx_freqs.resize(nof_carriers);
+  cur_rx_freqs.resize(nof_carriers);
+
   // Init and start Radio
   char* device_args = nullptr;
   if (args.device_args != "auto") {
@@ -323,12 +326,14 @@ void radio::set_rx_freq(const uint32_t& carrier_idx, const double& freq)
   // Map carrier index to physical channel
   if (rx_channel_mapping.allocate_freq(carrier_idx, freq)) {
     uint32_t physical_channel_idx = rx_channel_mapping.get_carrier_idx(carrier_idx);
-    if ((physical_channel_idx + 1) * nof_antennas <= nof_channels) {
-      for (uint32_t i = 0; i < nof_antennas; i++) {
     log_h->info("Mapping RF channel %d to logical carrier %d on f_rx=%.1f MHz\n",
-                    physical_channel_idx * nof_antennas + i,
+                physical_channel_idx * nof_antennas,
                 carrier_idx,
                 freq / 1e6);
+    if (cur_rx_freqs[physical_channel_idx] != freq) {
+      if ((physical_channel_idx + 1) * nof_antennas <= nof_channels) {
+        cur_rx_freqs[physical_channel_idx] = freq;
+        for (uint32_t i = 0; i < nof_antennas; i++) {
           srslte_rf_set_rx_freq(&rf_device, physical_channel_idx * nof_antennas + i, freq + freq_offset);
         }
       } else {
@@ -337,6 +342,9 @@ void radio::set_rx_freq(const uint32_t& carrier_idx, const double& freq)
                      nof_antennas,
                      nof_channels);
       }
+    } else {
+      log_h->info("RF channel %d already on freq\n", physical_channel_idx * nof_antennas);
+    }
   } else {
     log_h->error("set_rx_freq: Could not allocate frequency %.1f MHz to carrier %d\n", freq / 1e6, carrier_idx);
   }
@@ -378,12 +386,14 @@ void radio::set_tx_freq(const uint32_t& carrier_idx, const double& freq)
   // Map carrier index to physical channel
   if (tx_channel_mapping.allocate_freq(carrier_idx, freq)) {
     uint32_t physical_channel_idx = tx_channel_mapping.get_carrier_idx(carrier_idx);
-    if ((physical_channel_idx + 1) * nof_antennas <= nof_channels) {
-      for (uint32_t i = 0; i < nof_antennas; i++) {
     log_h->info("Mapping RF channel %d to logical carrier %d on f_tx=%.1f MHz\n",
-                    physical_channel_idx * nof_antennas + i,
+                physical_channel_idx * nof_antennas,
                 carrier_idx,
                 freq / 1e6);
+    if (cur_tx_freqs[physical_channel_idx] != freq) {
+      if ((physical_channel_idx + 1) * nof_antennas <= nof_channels) {
+        cur_tx_freqs[physical_channel_idx] = freq;
+        for (uint32_t i = 0; i < nof_antennas; i++) {
           srslte_rf_set_tx_freq(&rf_device, physical_channel_idx * nof_antennas + i, freq + freq_offset);
         }
       } else {
@@ -392,6 +402,9 @@ void radio::set_tx_freq(const uint32_t& carrier_idx, const double& freq)
                      nof_antennas,
                      nof_channels);
       }
+    } else {
+      log_h->info("RF channel %d already on freq\n", physical_channel_idx * nof_antennas);
+    }
   } else {
     log_h->error("set_tx_freq: Could not allocate frequency %.1f MHz to carrier %d\n", freq / 1e6, carrier_idx);
   }

srsue/hdr/phy/phy.h

@@ -133,7 +133,7 @@ private:
   bool                    is_configured = false;
   uint32_t                nof_workers   = 0;
 
-  const static int SF_RECV_THREAD_PRIO = 1;
+  const static int SF_RECV_THREAD_PRIO = 0;
   const static int WORKERS_THREAD_PRIO = 2;
 
   srslte::radio_interface_phy*                      radio = nullptr;

srsue/hdr/phy/sync.h

@@ -166,9 +166,8 @@ private:
   bool set_frequency();
   bool set_cell();
 
-  bool radio_is_overflow     = false;
-  bool radio_overflow_return = false;
   bool running               = false;
+  bool is_overflow           = false;
 
   // Objects for internal use
   search                                              search_p;

srsue/hdr/stack/mac/proc_ra.h

@@ -61,6 +61,7 @@ public:
     noncontention_enabled = false;
     next_preamble_idx     = 0;
     next_prach_mask       = 0;
+    current_task_id       = 0;
   };
 
   ~ra_proc();
@@ -94,8 +95,8 @@ public:
   bool contention_resolution_id_received(uint64_t uecri);
   void start_pcap(srslte::mac_pcap* pcap);
 
-  void notify_phy_config_completed();
+  void notify_phy_config_completed(uint32_t task_id);
-  void notify_ra_completed();
+  void notify_ra_completed(uint32_t task_id);
 
 private:
   void state_pdcch_setup();
@@ -139,6 +140,8 @@ private:
   uint32_t ra_rnti;
   uint32_t ra_tti;
   uint32_t current_ta;
+  // The task_id is a unique number associated with each RA procedure used to track background tasks
+  uint32_t current_task_id;
 
   srslte_softbuffer_rx_t softbuffer_rar;
 

srsue/src/main.cc

@@ -361,7 +361,7 @@ static int parse_args(all_args_t* args, int argc, char* argv[])
      "RSRP threshold (in dBm) above which the UE considers to be in-sync")
 
     ("phy.in_sync_snr_db_th",
-     bpo::value<float>(&args->phy.in_sync_snr_db_th)->default_value(1.0f),
+     bpo::value<float>(&args->phy.in_sync_snr_db_th)->default_value(3.0f),
      "SNR threshold (in dB) above which the UE considers to be in-sync")
 
     ("phy.nof_in_sync_events",

srsue/src/phy/sf_worker.cc

@@ -198,15 +198,19 @@ void sf_worker::set_config(uint32_t cc_idx, srslte::phy_cfg_t& phy_cfg)
 
 void sf_worker::work_imp()
 {
-  std::lock_guard<std::mutex> lock(mutex);
+
   srslte::rf_buffer_t         tx_signal_ptr = {};
   if (!cell_initiated) {
     phy->worker_end(this, false, tx_signal_ptr, 0, tx_time);
   }
 
-  /***** Downlink Processing *******/
-
   bool     rx_signal_ok    = false;
+  bool     tx_signal_ready = false;
+  uint32_t nof_samples     = SRSLTE_SF_LEN_PRB(cell.nof_prb);
+
+  /***** Downlink Processing *******/
+  {
+    std::lock_guard<std::mutex> lock(mutex);
 
     // Loop through all carriers. carrier_idx=0 is PCell
     for (uint32_t carrier_idx = 0; carrier_idx < cc_workers.size(); carrier_idx++) {
@@ -228,9 +232,6 @@ void sf_worker::work_imp()
 
     /***** Uplink Generation + Transmission *******/
 
-  bool     tx_signal_ready = false;
-  uint32_t nof_samples     = SRSLTE_SF_LEN_PRB(cell.nof_prb);
-
     /* If TTI+4 is an uplink subframe (TODO: Support short PRACH and SRS in UpPts special subframes) */
     if ((srslte_sfidx_tdd_type(tdd_config, TTI_TX(tti) % 10) == SRSLTE_TDD_SF_U) || cell.frame_type == SRSLTE_FDD) {
       // Generate Uplink signal if no PRACH pending
@@ -254,6 +255,7 @@ void sf_worker::work_imp()
         }
       }
     }
+  }
 
   // Set PRACH buffer signal pointer
   if (prach_ptr) {

srsue/src/phy/sync.cc

@@ -134,8 +134,6 @@ void sync::stop()
 
 void sync::reset()
 {
-  radio_is_overflow     = false;
-  radio_overflow_return = false;
   in_sync_cnt           = 0;
   out_of_sync_cnt       = 0;
   time_adv_sec          = 0;
@@ -442,11 +440,17 @@ void sync::run_thread()
                 force_camping_sfn_sync = true;
               }
 
+              if (is_overflow) {
+                force_camping_sfn_sync = true;
+                is_overflow            = false;
+                log_h->info("Detected overflow, trying to resync SFN\n");
+              }
+
               // Force decode MIB if required
               if (force_camping_sfn_sync) {
                 uint32_t _tti                = 0;
                 temp_cell                    = cell;
-                sync::sfn_sync::ret_code ret = sfn_p.decode_mib(&temp_cell, &_tti, &sf_buffer, mib);
+                sync::sfn_sync::ret_code ret = sfn_p.decode_mib(&temp_cell, &_tti, &sync_buffer, mib);
                 if (ret == sfn_sync::SFN_FOUND) {
                   // Force tti
                   tti = _tti;
@@ -459,7 +463,11 @@ void sync::run_thread()
                                  "reselection to cells with different MIB is not supported\n");
                     log_h->console("Detected cell during SFN synchronization differs from configured cell. Cell "
                                    "reselection to cells with different MIB is not supported\n");
+                  } else {
+                    log_h->info("SFN resynchronized successfully\n");
                   }
+                } else {
+                  log_h->warning("SFN not yet synchronized, sending out-of-sync\n");
                 }
               }
 
@@ -571,39 +579,6 @@ void sync::run_thread()
         break;
     }
 
-    /* Radio overflow detected. If CAMPING, go through SFN sync again and when
-     * SFN is found again go back to camping
-     */
-    if (!rrc_mutex.try_lock()) {
-      if (radio_is_overflow) {
-        // If we are coming back from an overflow
-        if (radio_overflow_return) {
-          if (phy_state.is_camping()) {
-            log_h->info("Successfully resynchronized after overflow. Returning to CAMPING\n");
-            radio_overflow_return = false;
-            radio_is_overflow     = false;
-          } else if (phy_state.is_idle()) {
-            log_h->warning("Could not synchronize SFN after radio overflow. Trying again\n");
-            stack->out_of_sync();
-            phy_state.force_sfn_sync();
-          }
-        } else {
-          // Overflow has occurred now while camping
-          if (phy_state.is_camping()) {
-            log_h->warning("Detected radio overflow while camping. Resynchronizing cell\n");
-            sfn_p.reset();
-            srslte_ue_sync_reset(&ue_sync);
-            phy_state.force_sfn_sync();
-            radio_overflow_return = true;
-          } else {
-            radio_is_overflow = false;
-          }
-          // If overflow occurs in any other state, it does not harm
-        }
-      }
-      rrc_mutex.unlock();
-    }
-
     // Increase TTI counter
     tti = (tti + 1) % 10240;
   }
@@ -616,7 +591,7 @@ void sync::run_thread()
  */
 void sync::radio_overflow()
 {
-  radio_is_overflow = true;
+  is_overflow = true;
 }
 
 void sync::radio_error()

srsue/src/stack/mac/proc_ra.cc

@@ -238,15 +238,17 @@ void ra_proc::state_completition()
 {
   state            = WAITING_COMPLETION;
   uint16_t rnti    = rntis->crnti;
-  stack->enqueue_background_task([this, rnti](uint32_t worker_id) {
+  uint32_t task_id = current_task_id;
+  stack->enqueue_background_task([this, rnti, task_id](uint32_t worker_id) {
     phy_h->set_crnti(rnti);
     // signal MAC RA proc to go back to idle
-    notify_ra_completed();
+    notify_ra_completed(task_id);
   });
 }
 
-void ra_proc::notify_phy_config_completed()
+void ra_proc::notify_phy_config_completed(uint32_t task_id)
 {
+  if (current_task_id == task_id) {
     if (state != WAITING_PHY_CONFIG) {
       rError("Received unexpected notification of PHY configuration completed\n");
     } else {
@@ -254,22 +256,34 @@ void ra_proc::notify_phy_config_completed()
     }
     // Jump directly to Resource selection
     resource_selection();
+  } else {
+    rError("Received old notification of PHY configuration (old task_id=%d, current_task_id=%d)\n",
+           task_id,
+           current_task_id);
+  }
 }
 
-void ra_proc::notify_ra_completed()
+void ra_proc::notify_ra_completed(uint32_t task_id)
 {
+  if (current_task_id == task_id) {
     if (state != WAITING_COMPLETION) {
       rError("Received unexpected notification of RA completion\n");
     } else {
       rInfo("RA waiting procedure completed\n");
     }
     state = IDLE;
+  } else {
+    rError("Received old notification of RA completition (old task_id=%d, current_task_id=%d)\n",
+           task_id,
+           current_task_id);
+  }
 }
 
 /* RA procedure initialization as defined in 5.1.1 */
 void ra_proc::initialization()
 {
   read_params();
+  current_task_id++;
   transmitted_contention_id   = 0;
   preambleTransmissionCounter = 1;
   mux_unit->msg3_flush();
@@ -277,10 +291,11 @@ void ra_proc::initialization()
 
   // Instruct phy to configure PRACH
   state            = WAITING_PHY_CONFIG;
-  stack->enqueue_background_task([this](uint32_t worker_id) {
+  uint32_t task_id = current_task_id;
+  stack->enqueue_background_task([this, task_id](uint32_t worker_id) {
     phy_h->configure_prach_params();
     // notify back MAC
-    stack->notify_background_task_result([this]() { notify_phy_config_completed(); });
+    stack->notify_background_task_result([this, task_id]() { notify_phy_config_completed(task_id); });
   });
 }
 

srsue/src/stack/rrc/rrc_procedures.cc

@@ -1002,6 +1002,7 @@ rrc::go_idle_proc::go_idle_proc(srsue::rrc* rrc_) : rrc_ptr(rrc_)
 proc_outcome_t rrc::go_idle_proc::init()
 {
   Info("Starting...\n");
+  rlc_flush_timer.run();
   return step();
 }
 

srsue/ue.conf.example

@@ -343,7 +343,7 @@ enable = false
 #force_ul_amplitude = 0
 
 #in_sync_rsrp_dbm_th    = -130.0
-#in_sync_snr_db_th      = 1.0
+#in_sync_snr_db_th      = 3.0
 #nof_in_sync_events     = 10
 #nof_out_of_sync_events = 20