From 9dddec48e7f5516e0c603d3eb540a169b50fa5a9 Mon Sep 17 00:00:00 2001 From: Martin Braun Date: Thu, 29 Mar 2018 16:36:29 -0700 Subject: rfnoc: Update logging in some blocks Updated the following blocks and components: Radio, DmaFIFO, block_ctrl_base and node_ctrl_base, blockdef_xml_impl, device3_impl. No functional changes. - Demoted some log messages - Consistent log style (use unique_id()) - Some adaptation of coding style where close to log statements --- host/lib/rfnoc/block_ctrl_base.cpp | 63 +++++++++++++++-------------- host/lib/rfnoc/blockdef_xml_impl.cpp | 20 +++++---- host/lib/rfnoc/dma_fifo_block_ctrl_impl.cpp | 7 ++-- host/lib/rfnoc/node_ctrl_base.cpp | 2 +- host/lib/rfnoc/radio_ctrl_impl.cpp | 3 +- host/lib/usrp/device3/device3_impl.cpp | 48 ++++++++++++++++------ 6 files changed, 87 insertions(+), 56 deletions(-) (limited to 'host/lib') diff --git a/host/lib/rfnoc/block_ctrl_base.cpp b/host/lib/rfnoc/block_ctrl_base.cpp index 20d79d262..246ba7196 100644 --- a/host/lib/rfnoc/block_ctrl_base.cpp +++ b/host/lib/rfnoc/block_ctrl_base.cpp @@ -20,8 +20,6 @@ #include #include -#define UHD_BLOCK_LOG() UHD_LOGGER_TRACE("RFNOC") - using namespace uhd; using namespace uhd::rfnoc; using std::string; @@ -37,14 +35,16 @@ block_ctrl_base::block_ctrl_base( _noc_id(sr_read64(SR_READBACK_REG_ID)), _compat_num(sr_read64(SR_READBACK_COMPAT)) { - UHD_BLOCK_LOG() << "block_ctrl_base()" ; - /*** Identify this block (NoC-ID, block-ID, and block definition) *******/ // Read NoC-ID (name is passed in through make_args): _block_def = blockdef::make_from_noc_id(_noc_id); - if (_block_def) UHD_BLOCK_LOG() << "Found valid blockdef" ; - if (not _block_def) + if (not _block_def) { + UHD_LOG_DEBUG("RFNOC", + "No block definition found, using default block configuration " + "for block with NOC ID: " + str(boost::format("0x%08X") % noc_id) + ); _block_def = blockdef::make_from_noc_id(DEFAULT_NOC_ID); + } UHD_ASSERT_THROW(_block_def); // For the block ID, we start with block count 0 and increase until // we get a block ID that's not already registered: @@ -52,9 +52,10 @@ block_ctrl_base::block_ctrl_base( while (_tree->exists("xbar/" + _block_id.get_local())) { _block_id++; } - UHD_BLOCK_LOG() - << "NOC ID: " << str(boost::format("0x%016X ") % _noc_id) - << "Block ID: " << _block_id ; + UHD_LOG_INFO(unique_id(), str( + boost::format("Initializing block control (NOC ID: 0x%016X)") + % _noc_id + )); /*** Check compat number ************************************************/ assert_fpga_compat( @@ -62,7 +63,7 @@ block_ctrl_base::block_ctrl_base( NOC_SHELL_COMPAT_MINOR, _compat_num, "noc_shell", - "RFNoC", + unique_id(), false /* fail_on_minor_behind */ ); @@ -75,7 +76,7 @@ block_ctrl_base::block_ctrl_base( /*** Configure ports ****************************************************/ size_t n_valid_input_buffers = 0; - for(const size_t ctrl_port: get_ctrl_ports()) { + for (const size_t ctrl_port : get_ctrl_ports()) { // Set command times to sensible defaults set_command_tick_rate(1.0, ctrl_port); set_command_time(time_spec_t(0.0), ctrl_port); @@ -113,10 +114,12 @@ block_ctrl_base::block_ctrl_base( _init_port_defs("out", _block_def->get_output_ports()); // FIXME this warning always fails until the input buffer code above is fixed if (_tree->list(_root_path / "ports/in").size() != n_valid_input_buffers) { - UHD_LOGGER_WARNING("RFNOC") << + UHD_LOGGER_WARNING(unique_id()) << boost::format("[%s] defines %d input buffer sizes, but %d input ports") - % get_block_id().get() % n_valid_input_buffers % _tree->list(_root_path / "ports/in").size() - ; + % get_block_id().get() + % n_valid_input_buffers + % _tree->list(_root_path / "ports/in").size() + ; } /*** Init default block args ********************************************/ @@ -140,9 +143,13 @@ void block_ctrl_base::_init_port_defs( if (not _tree->exists(port_path)) { _tree->create(port_path); } - UHD_RFNOC_BLOCK_TRACE() << "Adding port definition at " << port_path - << boost::format(": type = '%s' pkt_size = '%s' vlen = '%s'") % port_def["type"] % port_def["pkt_size"] % port_def["vlen"] - ; + UHD_LOGGER_TRACE(unique_id()) + << "Adding port definition at " << port_path + << boost::format(": type = '%s' pkt_size = '%s' vlen = '%s'") + % port_def["type"] + % port_def["pkt_size"] + % port_def["vlen"] + ; _tree->access(port_path).set(port_def); port_index++; } @@ -152,12 +159,12 @@ void block_ctrl_base::_init_block_args() { blockdef::args_t args = _block_def->get_args(); fs_path arg_path = _root_path / "args"; - for(const size_t port: get_ctrl_ports()) { + for (const size_t port : get_ctrl_ports()) { _tree->create(arg_path / port); } // First, create all nodes. - for(const blockdef::arg_t &arg: args) { + for (const auto& arg : args) { fs_path arg_type_path = arg_path / arg["port"] / arg["name"] / "type"; _tree->create(arg_type_path).set(arg["type"]); fs_path arg_val_path = arg_path / arg["port"] / arg["name"] / "value"; @@ -171,7 +178,7 @@ void block_ctrl_base::_init_block_args() // TODO: Add coercer #define _SUBSCRIBE_CHECK_AND_RUN(type, arg_tag, error_message) \ _tree->access(arg_val_path).add_coerced_subscriber(boost::bind((&nocscript::block_iface::run_and_check), _nocscript_iface, arg[#arg_tag], error_message)) - for(const blockdef::arg_t &arg: args) { + for (const auto& arg : args) { fs_path arg_val_path = arg_path / arg["port"] / arg["name"] / "value"; if (not arg["check"].empty()) { if (arg["type"] == "string") { _SUBSCRIBE_CHECK_AND_RUN(string, check, arg["check_message"]); } @@ -190,7 +197,7 @@ void block_ctrl_base::_init_block_args() } // Finally: Set the values. This will call subscribers, if we have any. - for(const blockdef::arg_t &arg: args) { + for (const auto& arg : args) { fs_path arg_val_path = arg_path / arg["port"] / arg["name"] / "value"; if (not arg["value"].empty()) { if (arg["type"] == "int_vector") { throw uhd::runtime_error("not yet implemented: int_vector"); } @@ -228,8 +235,6 @@ std::vector block_ctrl_base::get_ctrl_ports() const void block_ctrl_base::sr_write(const uint32_t reg, const uint32_t data, const size_t port) { - //UHD_BLOCK_LOG() << " "; - //UHD_RFNOC_BLOCK_TRACE() << boost::format("sr_write(%d, %08X, %d)") % reg % data % port ; if (not _ctrl_ifaces.count(port)) { throw uhd::key_error(str(boost::format("[%s] sr_write(): No such port: %d") % get_block_id().get() % port)); } @@ -258,7 +263,6 @@ void block_ctrl_base::sr_write(const std::string ®, const uint32_t data, cons } reg_addr = uint32_t(_tree->access(_root_path / "registers" / "sr" / reg).get()); } - UHD_RFNOC_BLOCK_TRACE() << boost::format("sr_write(%s, %08X) ==> ") % reg % data ; return sr_write(reg_addr, data, port); } @@ -396,11 +400,11 @@ void block_ctrl_base::clear_command_time(const size_t port) void block_ctrl_base::clear() { - UHD_RFNOC_BLOCK_TRACE() << "block_ctrl_base::clear() " ; + UHD_LOG_TRACE(unique_id(), "block_ctrl_base::clear()"); // Call parent... node_ctrl_base::clear(); // ...then child - for(const size_t port_index: get_ctrl_ports()) { + for (const size_t port_index : get_ctrl_ports()) { _clear(port_index); } } @@ -519,7 +523,6 @@ stream_sig_t block_ctrl_base::_resolve_port_def(const blockdef::port_t &port_def } else { stream_sig.item_type = port_def["type"]; } - //UHD_RFNOC_BLOCK_TRACE() << " item type: " << stream_sig.item_type ; // Vector length if (port_def.is_variable("vlen")) { @@ -530,7 +533,6 @@ stream_sig_t block_ctrl_base::_resolve_port_def(const blockdef::port_t &port_def } else { stream_sig.vlen = boost::lexical_cast(port_def["vlen"]); } - //UHD_RFNOC_BLOCK_TRACE() << " vector length: " << stream_sig.vlen ; // Packet size if (port_def.is_variable("pkt_size")) { @@ -552,7 +554,6 @@ stream_sig_t block_ctrl_base::_resolve_port_def(const blockdef::port_t &port_def } else { stream_sig.packet_size = boost::lexical_cast(port_def["pkt_size"]); } - //UHD_RFNOC_BLOCK_TRACE() << " packet size: " << stream_sig.vlen ; return stream_sig; } @@ -563,13 +564,13 @@ stream_sig_t block_ctrl_base::_resolve_port_def(const blockdef::port_t &port_def **********************************************************************/ void block_ctrl_base::_clear(const size_t port) { - UHD_RFNOC_BLOCK_TRACE() << "block_ctrl_base::_clear() " ; + UHD_LOG_TRACE(unique_id(), "block_ctrl_base::_clear()"); sr_write(SR_CLEAR_TX_FC, 0x00C1EA12, port); // 'CLEAR', but we can write anything, really sr_write(SR_CLEAR_RX_FC, 0x00C1EA12, port); // 'CLEAR', but we can write anything, really } void block_ctrl_base::_set_command_time(const time_spec_t & /*time_spec*/, const size_t /*port*/) { - UHD_RFNOC_BLOCK_TRACE() << "block_ctrl_base::_set_command_time() "; + UHD_LOG_TRACE(unique_id(), "block_ctrl_base::_set_command_time()"); } // vim: sw=4 et: diff --git a/host/lib/rfnoc/blockdef_xml_impl.cpp b/host/lib/rfnoc/blockdef_xml_impl.cpp index d8f749aa0..50faf6905 100644 --- a/host/lib/rfnoc/blockdef_xml_impl.cpp +++ b/host/lib/rfnoc/blockdef_xml_impl.cpp @@ -213,7 +213,9 @@ public: } } } catch (std::exception &e) { - UHD_LOGGER_WARNING("RFNOC") << "has_noc_id(): caught exception " << e.what() ; + UHD_LOGGER_WARNING("RFNOC") + << "has_noc_id(): caught exception " << e.what() + << " while parsing file: " << filename.string(); return false; } return false; @@ -223,7 +225,11 @@ public: _type(type), _noc_id(noc_id) { - //UHD_LOGGER_INFO("RFNOC") << "Reading XML file: " << filename.string().c_str() ; + UHD_LOGGER_DEBUG("RFNOC") << + boost::format("Reading XML file %s for NOC ID 0x%08X") + % filename.string().c_str() + % noc_id + ; read_xml(filename.string(), _pt); try { // Check key is valid @@ -352,7 +358,8 @@ public: arg["type"] = "string"; } if (not arg.is_valid()) { - UHD_LOGGER_WARNING("RFNOC") << boost::format("Found invalid argument: %s") % arg.to_string() ; + UHD_LOGGER_WARNING("RFNOC") + << "Found invalid argument: " << arg.to_string(); is_valid = false; } args.push_back(arg); @@ -408,15 +415,14 @@ blockdef::sptr blockdef::make_from_noc_id(uint64_t noc_id) std::vector valid; // Check if any of the paths exist - for(const fs::path &base_path: paths) { + for (const auto& base_path : paths) { fs::path this_path = base_path / XML_BLOCKS_SUBDIR; if (fs::exists(this_path) and fs::is_directory(this_path)) { valid.push_back(this_path); } } - if (valid.empty()) - { + if (valid.empty()) { throw uhd::assertion_error( "Failed to find a valid XML path for RFNoC blocks.\n" "Try setting the enviroment variable UHD_RFNOC_DIR " @@ -425,7 +431,7 @@ blockdef::sptr blockdef::make_from_noc_id(uint64_t noc_id) } // Iterate over all paths - for(const fs::path &path: valid) { + for (const auto& path : valid) { // Iterate over all .xml files fs::directory_iterator end_itr; for (fs::directory_iterator i(path); i != end_itr; ++i) { diff --git a/host/lib/rfnoc/dma_fifo_block_ctrl_impl.cpp b/host/lib/rfnoc/dma_fifo_block_ctrl_impl.cpp index e27c20809..16ad7db6f 100644 --- a/host/lib/rfnoc/dma_fifo_block_ctrl_impl.cpp +++ b/host/lib/rfnoc/dma_fifo_block_ctrl_impl.cpp @@ -34,19 +34,20 @@ public: _perifs[i].depth = DEFAULT_SIZE; _perifs[i].core = dma_fifo_core_3000::make(_perifs[i].ctrl, USER_SR_BASE, USER_RB_BASE); _perifs[i].core->resize(_perifs[i].base_addr, _perifs[i].depth); - UHD_LOGGER_INFO("RFNOC DMA FIFO") << boost::format("Running BIST for FIFO %d... ") % i; + UHD_LOG_DEBUG(unique_id(), "Running BIST for FIFO " << i); if (_perifs[i].core->ext_bist_supported()) { uint32_t bisterr = _perifs[i].core->run_bist(); if (bisterr != 0) { throw uhd::runtime_error(str(boost::format("BIST failed! (code: %d)\n") % bisterr)); } else { double throughput = _perifs[i].core->get_bist_throughput(); - UHD_LOGGER_INFO("RFNOC DMA FIFO") << (boost::format("BIST passed (Throughput: %.0f MB/s)") % (throughput/1e6)) ; + UHD_LOGGER_INFO(unique_id()) << (boost::format("BIST passed (Throughput: %.0f MB/s)") % (throughput/1e6)) ; } } else { if (_perifs[i].core->run_bist() == 0) { - UHD_LOGGER_INFO("RFNOC DMA FIFO") << "BIST passed"; + UHD_LOGGER_INFO(unique_id()) << "BIST passed"; } else { + UHD_LOGGER_ERROR(unique_id()) << "BIST failed!"; throw uhd::runtime_error("BIST failed!"); } } diff --git a/host/lib/rfnoc/node_ctrl_base.cpp b/host/lib/rfnoc/node_ctrl_base.cpp index 7828cd514..60496798d 100644 --- a/host/lib/rfnoc/node_ctrl_base.cpp +++ b/host/lib/rfnoc/node_ctrl_base.cpp @@ -20,7 +20,7 @@ std::string node_ctrl_base::unique_id() const void node_ctrl_base::clear() { - UHD_RFNOC_BLOCK_TRACE() << "node_ctrl_base::clear() " ; + UHD_LOG_TRACE(unique_id(), "node_ctrl_base::clear()"); // Reset connections: _upstream_nodes.clear(); _downstream_nodes.clear(); diff --git a/host/lib/rfnoc/radio_ctrl_impl.cpp b/host/lib/rfnoc/radio_ctrl_impl.cpp index 5347150ba..2479d889a 100644 --- a/host/lib/rfnoc/radio_ctrl_impl.cpp +++ b/host/lib/rfnoc/radio_ctrl_impl.cpp @@ -120,9 +120,10 @@ void radio_ctrl_impl::_register_loopback_self_test(size_t chan) return; // exit on any failure } } - UHD_LOGGER_INFO("RFNOC RADIO") << "Register loopback test passed"; + UHD_LOG_DEBUG(unique_id(), "Register loopback test passed"); } + /**************************************************************************** * API calls ***************************************************************************/ diff --git a/host/lib/usrp/device3/device3_impl.cpp b/host/lib/usrp/device3/device3_impl.cpp index 6f1719500..772008a38 100644 --- a/host/lib/usrp/device3/device3_impl.cpp +++ b/host/lib/usrp/device3/device3_impl.cpp @@ -13,8 +13,6 @@ #include #include -#define UHD_DEVICE3_LOG() UHD_LOGGER_TRACE("DEVICE3") - using namespace uhd::usrp; device3_impl::device3_impl() @@ -108,7 +106,6 @@ void device3_impl::enumerate_rfnoc_blocks( // TODO: Clear out all the old block control classes // 3) Create new block controllers for (size_t i = 0; i < n_blocks; i++) { - UHD_DEVICE3_LOG() << "[RFNOC] ------- Block Setup -----------" ; // First, make a transport for port number zero, because we always need that: ctrl_sid.set_dst_xbarport(base_port + i); ctrl_sid.set_dst_blockport(0); @@ -117,22 +114,39 @@ void device3_impl::enumerate_rfnoc_blocks( CTRL, transport_args ); - UHD_DEVICE3_LOG() << str(boost::format("Setting up NoC-Shell Control for port #0 (SID: %s)...") % xport.send_sid.to_pp_string_hex()); + UHD_LOG_TRACE("DEVICE3", + str(boost::format("Setting up NoC-Shell Control for port #0 (SID: %s)...") + % xport.send_sid.to_pp_string_hex()) + ); uhd::rfnoc::ctrl_iface::sptr ctrl = uhd::rfnoc::ctrl_iface::make( - xport, - str(boost::format("CE_%02d_Port_%02X") % i % ctrl_sid.get_dst_endpoint()) + xport, + str(boost::format("CE_%02d_Port_%02X") + % i + % ctrl_sid.get_dst_endpoint()) + ); + uint64_t noc_id = ctrl->send_cmd_pkt( + uhd::rfnoc::SR_READBACK, + uhd::rfnoc::SR_READBACK_REG_ID, + true ); - uint64_t noc_id = ctrl->send_cmd_pkt(uhd::rfnoc::SR_READBACK, uhd::rfnoc::SR_READBACK_REG_ID, true); - UHD_DEVICE3_LOG() << str(boost::format("Port %d: Found NoC-Block with ID %016X.") % int(ctrl_sid.get_dst_endpoint()) % noc_id) ; + UHD_LOG_DEBUG("DEVICE3", str( + boost::format("Port 0x%02X: Found NoC-Block with ID %016X.") + % int(ctrl_sid.get_dst_endpoint()) + % noc_id + )); uhd::rfnoc::make_args_t make_args; uhd::rfnoc::blockdef::sptr block_def = uhd::rfnoc::blockdef::make_from_noc_id(noc_id); if (not block_def) { - UHD_DEVICE3_LOG() << "Using default block configuration." ; - block_def = uhd::rfnoc::blockdef::make_from_noc_id(uhd::rfnoc::DEFAULT_NOC_ID); + UHD_LOG_WARNING("DEVICE3", + "No block definition found, using default block configuration " + "for block with NOC ID: " + str(boost::format("0x%08X") % noc_id) + ); + block_def = uhd::rfnoc::blockdef::make_from_noc_id( + uhd::rfnoc::DEFAULT_NOC_ID); } UHD_ASSERT_THROW(block_def); make_args.ctrl_ifaces[0] = ctrl; - for(const size_t port_number: block_def->get_all_port_numbers()) { + for (const size_t port_number : block_def->get_all_port_numbers()) { if (port_number == 0) { // We've already set this up continue; } @@ -142,14 +156,22 @@ void device3_impl::enumerate_rfnoc_blocks( CTRL, transport_args ); - UHD_DEVICE3_LOG() << str(boost::format("Setting up NoC-Shell Control for port #%d (SID: %s)...") % port_number % xport1.send_sid.to_pp_string_hex()); + UHD_LOG_TRACE("DEVICE3", str( + boost::format("Setting up NoC-Shell Control for port #%d " + "(SID: %s)...") + % port_number + % xport1.send_sid.to_pp_string_hex() + )); uhd::rfnoc::ctrl_iface::sptr ctrl1 = uhd::rfnoc::ctrl_iface::make( xport1, str(boost::format("CE_%02d_Port_%02d") % i % ctrl_sid.get_dst_endpoint()) ); - UHD_DEVICE3_LOG() << "OK" ; make_args.ctrl_ifaces[port_number] = ctrl1; } + UHD_LOG_TRACE("DEVICE3", + "All control transports successfully created for block with ID " << + str(boost::format("0x%08X") % noc_id) + ); make_args.base_address = xport.send_sid.get_dst(); make_args.device_index = device_index; -- cgit v1.2.3