Properly handle asynchronous UHD overflow messages

October 25, 2022 by [fito] :: tags: #GNURadio #UHD

When using the usrp_source block in GNUradio, you have likely experienced overflows. Overflows occur when the host does not consume data quickly enough.

## Problem

Whenever an overflow occurs, the usrp_source block provides an error message that looks like this:

usrp_source :error: In the last 778 ms, 1 overflows occurred.

Running the following flowgraph (test_overflow_msg.py) is an easy way to reproduce this situation:

#!eusr/bin/env python3
from gnuradio import blocks, gr, uhd

class OverflowTest(gr.top_block):
    def __init__(self):
        gr.top_block.__init__(self, self.__class__.__name__, catch_exceptions=True)
        self.sample_rate = 1e6

        # Blocks
        self.uhd_source = uhd.usrp_source("", uhd.stream_args(cpu_format="fc32", channels=range(1)))
        self.uhd_source.set_samp_rate(self.sample_rate)
        self.throttle = blocks.throttle(gr.sizeof_gr_complex*1, self.sample_rate / 10, True)
        self.null_sink = blocks.null_sink(gr.sizeof_gr_complex*1)

        # Connections
        self.connect(self.uhd_source, self.throttle, self.null_sink)

if __name__ == '__main__':
    tb = OverflowTest()
    tb.start()
    try:
        input('Press Enter to quit: ')
    except EOFError:
        pass
    tb.stop()
    tb.wait()

Here is the output:

# python /tmp/test_overflow_msg.py
[INFO] [UHD] linux; GNU C++ version 12.2.0; Boost_108000; UHD_4.3.0.HEAD-0-g1f8fd345
[INFO] [B200] Detected Device: B200
[INFO] [B200] Operating over USB 3.
[INFO] [B200] Initialize CODEC control...
[INFO] [B200] Initialize Radio control...
[INFO] [B200] Performing register loopback test...
[INFO] [B200] Register loopback test passed
[INFO] [B200] Setting master clock rate selection to 'automatic'.
[INFO] [B200] Asking for clock rate 16.000000 MHz...
[INFO] [B200] Actually got clock rate 16.000000 MHz.
[INFO] [B200] Asking for clock rate 32.000000 MHz...
[INFO] [B200] Actually got clock rate 32.000000 MHz.
Press Enter to quit: Ousrp_source :error: In the last 1174 ms, 1 overflows occurred.
Ousrp_source :error: In the last 778 ms, 1 overflows occurred.
Ousrp_source :error: In the last 778 ms, 1 overflows occurred.
OOusrp_source :error: In the last 1515 ms, 2 overflows occurred.
Ousrp_source :error: In the last 778 ms, 1 overflows occurred.
OOusrp_source :error: In the last 1515 ms, 2 overflows occurred.
Ousrp_source :error: In the last 778 ms, 1 overflows occurred.
OOusrp_source :error: In the last 1515 ms, 2 overflows occurred.

The problem arises when you want to handle overflows within your code; there's no way to do so.

## Proposal

To address this problem, the best approach is to modify gr-uhd/lib/usrp_source_impl.cc in GNU Radio.

The idea is to:

Define a new port (async_msgs) that outputs a dictionary containing the overflow count.
Utilize the existing loop that prints the overflows and, in the same place, send the event through async_msgs.

As of 25/10/2022, the diff would be:

❯ git diff
diff --git a/gr-uhd/grc/gen_uhd_usrp_blocks.py b/gr-uhd/grc/gen_uhd_usrp_blocks.py
index 371fe937c..42c28946e 100644
--- a/gr-uhd/grc/gen_uhd_usrp_blocks.py
+++ b/gr-uhd/grc/gen_uhd_usrp_blocks.py
@@ -119,10 +119,10 @@ outputs:
 % if sourk == 'sink':

 outputs:
+% endif
 -   domain: message
     id: async_msgs
     optional: true
-% endif

 templates:
     imports: |-
diff --git a/gr-uhd/lib/usrp_source_impl.cc b/gr-uhd/lib/usrp_source_impl.cc
index 510ab371c..c942076de 100644
--- a/gr-uhd/lib/usrp_source_impl.cc
+++ b/gr-uhd/lib/usrp_source_impl.cc
@@ -49,6 +49,7 @@ usrp_source_impl::usrp_source_impl(const ::uhd::device_addr_t& device_addr,

     _samp_rate = this->get_samp_rate();
     _samps_per_packet = 1;
+    message_port_register_out(ASYNC_MSGS_PORT_KEY);
     register_msg_cmd_handler(cmd_tag_key(),
                              [this](const pmt::pmt_t& tag, const int, const pmt::pmt_t&) {
                                  this->_cmd_handler_tag(tag);
@@ -647,6 +648,12 @@ int usrp_source_impl::work(int noutput_items,
                 std::chrono::duration_cast<std::chrono::milliseconds>(delta).count();
             d_logger->error(
                 "In the last {:d} ms, {:d} overflows occurred.", ms, _overflow_count);
+
+            pmt::pmt_t value = pmt::dict_add(
+                pmt::make_dict(), EVENT_CODE_OVERFLOW, pmt::from_uint64(_overflow_count));
+            pmt::pmt_t msg = pmt::cons(ASYNC_MSG_KEY, value);
+            message_port_pub(ASYNC_MSGS_PORT_KEY, msg);
+
             _overflow_count = 0;
         }
         // ignore overflows and try work again
diff --git a/gr-uhd/lib/usrp_source_impl.h b/gr-uhd/lib/usrp_source_impl.h
index 437fe7915..8cd986eb8 100644
--- a/gr-uhd/lib/usrp_source_impl.h

## Result

In order to test the proposal we just need to compile and modify a little bit test_overflow_msg.py:

❯ diff -c3 test_overflow_msg.py test_overflow_msg_new.py
*** test_overflow_msg.py
--- test_overflow_msg_new.py
***************
*** 15,23 ****
--- 15,25 ----
          self.uhd_source.set_samp_rate(self.sample_rate)
          self.throttle = blocks.throttle(gr.sizeof_gr_complex*1, self.sample_rate / 10, True)
          self.null_sink = blocks.null_sink(gr.sizeof_gr_complex*1)
+         self.print_msg = blocks.message_debug()

          # Connections
          self.connect(self.uhd_source, self.throttle, self.null_sink)
+         self.msg_connect((self.uhd_source, 'async_msgs'), (self.print_msg, 'print'))

  if __name__ == '__main__':
      tb = OverflowTest()

And the output is:

# python3 /tmp/test_overflow_msg_new.py
[INFO] [UHD] linux; GNU C++ version 13.2.1 20230801; Boost_108300; UHD_4.5.0.HEAD-0-g471af98f
[INFO] [B200] Detected Device: B200
[INFO] [B200] Operating over USB 3.
[INFO] [B200] Initialize CODEC control...
[INFO] [B200] Initialize Radio control...
[INFO] [B200] Performing register loopback test...
[INFO] [B200] Register loopback test passed
[INFO] [B200] Setting master clock rate selection to 'automatic'.
[INFO] [B200] Asking for clock rate 16.000000 MHz...
[INFO] [B200] Actually got clock rate 16.000000 MHz.
[INFO] [B200] Asking for clock rate 32.000000 MHz...
[INFO] [B200] Actually got clock rate 32.000000 MHz.
Press Enter to quit: Ousrp_source :error: In the last 1110 ms, 1 overflows occurred.
******* MESSAGE DEBUG PRINT ********
(uhd_async_msg (overflows . 1))
************************************
Ousrp_source :error: In the last 778 ms, 1 overflows occurred.
******* MESSAGE DEBUG PRINT ********
(uhd_async_msg (overflows . 1))
************************************
Ousrp_source :error: In the last 778 ms, 1 overflows occurred.
******* MESSAGE DEBUG PRINT ********
(uhd_async_msg (overflows . 1))
************************************
OOusrp_source :error: In the last 1515 ms, 2 overflows occurred.
******* MESSAGE DEBUG PRINT ********
(uhd_async_msg (overflows . 2))
************************************
Ousrp_source :error: In the last 778 ms, 1 overflows occurred.
******* MESSAGE DEBUG PRINT ********
(uhd_async_msg (overflows . 1))
************************************

## Update (3/1/2023)

We proposed the change to be added into GNU Radio and it's already merged since 3.10.5.1.