From 5cc8858d8f167b521e412883bb477e73f88280cb Mon Sep 17 00:00:00 2001 From: Harald Welte Date: Fri, 17 Aug 2018 19:55:38 +0200 Subject: logging: Introduce new "DDEV" category for device-specific code The DMAIN category got too overloaded. Let's have the code in Transceive52M/device/* use the new DDEV category. Also, in some cases the log levels have been adjusted to ensure that enabling INFO level should not result in a complete overflow of messages during normal operation. Change-Id: I844fe4a75bf277cd3cc5bd8fa06e06ad97b2ea95 --- CommonLibs/debug.c | 8 +- CommonLibs/debug.h | 1 + Transceiver52M/device/lms/LMSDevice.cpp | 112 ++++++++++----------- Transceiver52M/device/uhd/UHDDevice.cpp | 152 ++++++++++++++--------------- Transceiver52M/device/usrp1/USRPDevice.cpp | 78 +++++++-------- 5 files changed, 179 insertions(+), 172 deletions(-) diff --git a/CommonLibs/debug.c b/CommonLibs/debug.c index 01854c0..c6de21a 100644 --- a/CommonLibs/debug.c +++ b/CommonLibs/debug.c @@ -10,9 +10,15 @@ static const struct log_info_cat default_categories[] = { .color = NULL, .enabled = 1, .loglevel = LOGL_NOTICE, }, + [DDEV] = { + .name = "DDEV", + .description = "Device/Driver specific code", + .color = NULL, + .enabled = 1, .loglevel = LOGL_INFO, + }, [DLMS] = { .name = "DLMS", - .description = "LimeSuite category", + .description = "Logging from within LimeSuite itself", .color = NULL, .enabled = 1, .loglevel = LOGL_NOTICE, }, diff --git a/CommonLibs/debug.h b/CommonLibs/debug.h index 06ad74e..f8f6239 100644 --- a/CommonLibs/debug.h +++ b/CommonLibs/debug.h @@ -5,5 +5,6 @@ extern const struct log_info log_info; /* Debug Areas of the code */ enum { DMAIN, + DDEV, DLMS, }; diff --git a/Transceiver52M/device/lms/LMSDevice.cpp b/Transceiver52M/device/lms/LMSDevice.cpp index ffea505..881cfb7 100644 --- a/Transceiver52M/device/lms/LMSDevice.cpp +++ b/Transceiver52M/device/lms/LMSDevice.cpp @@ -46,7 +46,7 @@ LMSDevice::LMSDevice(size_t tx_sps, size_t rx_sps, InterfaceType iface, size_t c RadioDevice(tx_sps, rx_sps, iface, chans, lo_offset, tx_paths, rx_paths), m_lms_dev(NULL) { - LOG(INFO) << "creating LMS device..."; + LOGC(DDEV, INFO) << "creating LMS device..."; m_lms_stream_rx.resize(chans); m_lms_stream_tx.resize(chans); @@ -82,7 +82,7 @@ static void thread_enable_cancel(bool cancel) static void print_range(const char* name, lms_range_t *range) { - LOG(DEBUG) << name << ": Min=" << range->min << " Max=" << range->max + LOGC(DDEV, INFO) << name << ": Min=" << range->min << " Max=" << range->max << " Step=" << range->step; } @@ -96,36 +96,36 @@ int LMSDevice::open(const std::string &args, int ref, bool swap_channels) unsigned int i, n; int rc; - LOG(INFO) << "Opening LMS device.."; + LOGC(DDEV, INFO) << "Opening LMS device.."; LMS_RegisterLogHandler(&lms_log_callback); if ((n = LMS_GetDeviceList(NULL)) < 0) - LOG(ERROR) << "LMS_GetDeviceList(NULL) failed"; - LOG(DEBUG) << "Devices found: " << n; + LOGC(DDEV, ERROR) << "LMS_GetDeviceList(NULL) failed"; + LOGC(DDEV, INFO) << "Devices found: " << n; if (n < 1) return -1; info_list = new lms_info_str_t[n]; if (LMS_GetDeviceList(info_list) < 0) - LOG(ERROR) << "LMS_GetDeviceList(info_list) failed"; + LOGC(DDEV, ERROR) << "LMS_GetDeviceList(info_list) failed"; for (i = 0; i < n; i++) - LOG(DEBUG) << "Device [" << i << "]: " << info_list[i]; + LOGC(DDEV, INFO) << "Device [" << i << "]: " << info_list[i]; rc = LMS_Open(&m_lms_dev, info_list[0], NULL); if (rc != 0) { - LOG(ERROR) << "LMS_GetDeviceList() failed)"; + LOGC(DDEV, ERROR) << "LMS_GetDeviceList() failed)"; delete [] info_list; return -1; } delete [] info_list; - LOG(INFO) << "Init LMS device"; + LOGC(DDEV, INFO) << "Init LMS device"; if (LMS_Init(m_lms_dev) != 0) { - LOG(ERROR) << "LMS_Init() failed"; + LOGC(DDEV, ERROR) << "LMS_Init() failed"; return -1; } @@ -133,35 +133,35 @@ int LMSDevice::open(const std::string &args, int ref, bool swap_channels) goto out_close; print_range("Sample Rate", &range_sr); - LOG(DEBUG) << "Setting sample rate to " << GSMRATE*tx_sps << " " << tx_sps; + LOGC(DDEV, INFO) << "Setting sample rate to " << GSMRATE*tx_sps << " " << tx_sps; if (LMS_SetSampleRate(m_lms_dev, GSMRATE*tx_sps, 32) < 0) goto out_close; if (LMS_GetSampleRate(m_lms_dev, LMS_CH_RX, 0, &sr_host, &sr_rf)) goto out_close; - LOG(DEBUG) << "Sample Rate: Host=" << sr_host << " RF=" << sr_rf; + LOGC(DDEV, INFO) << "Sample Rate: Host=" << sr_host << " RF=" << sr_rf; /* FIXME: make this device/model dependent, like UHDDevice:dev_param_map! */ ts_offset = static_cast(8.9e-5 * GSMRATE * tx_sps); /* time * sample_rate */ switch (ref) { case REF_INTERNAL: - LOG(DEBUG) << "Setting Internal clock reference"; + LOGC(DDEV, INFO) << "Setting Internal clock reference"; /* Ugly API: Selecting clock source implicit by writing to VCTCXO DAC ?!? */ if (LMS_VCTCXORead(m_lms_dev, &dac_val) < 0) goto out_close; - LOG(DEBUG) << "Setting VCTCXO to " << dac_val; + LOGC(DDEV, INFO) << "Setting VCTCXO to " << dac_val; if (LMS_VCTCXOWrite(m_lms_dev, dac_val) < 0) goto out_close; break; case REF_EXTERNAL: - LOG(DEBUG) << "Setting External clock reference to " << 10000000.0; + LOGC(DDEV, INFO) << "Setting External clock reference to " << 10000000.0; /* Assume an external 10 MHz reference clock */ if (LMS_SetClockFreq(m_lms_dev, LMS_CLOCK_EXTREF, 10000000.0) < 0) goto out_close; break; default: - LOG(ALERT) << "Invalid reference type"; + LOGC(DDEV, ALERT) << "Invalid reference type"; goto out_close; } @@ -174,21 +174,21 @@ int LMSDevice::open(const std::string &args, int ref, bool swap_channels) lpfbw_rx = OSMO_MIN(OSMO_MAX(1.4001e6, range_lpfbw_rx.min), range_lpfbw_rx.max); lpfbw_tx = OSMO_MIN(OSMO_MAX(5.2e6, range_lpfbw_tx.min), range_lpfbw_tx.max); - LOG(DEBUG) << "LPFBW: Rx=" << lpfbw_rx << " Tx=" << lpfbw_tx; + LOGC(DDEV, INFO) << "LPFBW: Rx=" << lpfbw_rx << " Tx=" << lpfbw_tx; if (!set_antennas()) { - LOG(ALERT) << "LMS antenna setting failed"; + LOGC(DDEV, ALERT) << "LMS antenna setting failed"; return -1; } /* Perform Rx and Tx calibration */ for (i=0; i 0)) { rc = LMS_RecvStream(&m_lms_stream_rx[0], &buffer[0], len, &rx_metadata, 100); - LOG(DEBUG) << "Flush: Recv buffer of len " << rc << " at " << std::hex << rx_metadata.timestamp; + LOGC(DDEV, DEBUG) << "Flush: Recv buffer of len " << rc << " at " << std::hex << rx_metadata.timestamp; if (rc != len) { - LOG(ALERT) << "LMS: Device receive timed out"; + LOGC(DDEV, ALERT) << "LMS: Device receive timed out"; delete[] buffer; return false; } @@ -379,7 +379,7 @@ bool LMSDevice::flush_recv(size_t num_pkts) ts_initial = rx_metadata.timestamp + len; } - LOG(INFO) << "Initial timestamp " << ts_initial << std::endl; + LOGC(DDEV, INFO) << "Initial timestamp " << ts_initial << std::endl; delete[] buffer; return true; } @@ -389,18 +389,18 @@ bool LMSDevice::setRxAntenna(const std::string & ant, size_t chan) int idx; if (chan >= rx_paths.size()) { - LOG(ALERT) << "Requested non-existent channel " << chan; + LOGC(DDEV, ALERT) << "Requested non-existent channel " << chan; return false; } idx = get_ant_idx(ant, LMS_CH_RX, chan); if (idx < 0) { - LOG(ALERT) << "Invalid Rx Antenna"; + LOGC(DDEV, ALERT) << "Invalid Rx Antenna"; return false; } if (LMS_SetAntenna(m_lms_dev, LMS_CH_RX, chan, idx) < 0) { - LOG(ALERT) << "Unable to set Rx Antenna"; + LOGC(DDEV, ALERT) << "Unable to set Rx Antenna"; } return true; @@ -412,18 +412,18 @@ std::string LMSDevice::getRxAntenna(size_t chan) int idx; if (chan >= rx_paths.size()) { - LOG(ALERT) << "Requested non-existent channel " << chan; + LOGC(DDEV, ALERT) << "Requested non-existent channel " << chan; return ""; } idx = LMS_GetAntenna(m_lms_dev, LMS_CH_RX, chan); if (idx < 0) { - LOG(ALERT) << "Error getting Rx Antenna"; + LOGC(DDEV, ALERT) << "Error getting Rx Antenna"; return ""; } if (LMS_GetAntennaList(m_lms_dev, LMS_CH_RX, chan, name_list) < idx) { - LOG(ALERT) << "Error getting Rx Antenna List"; + LOGC(DDEV, ALERT) << "Error getting Rx Antenna List"; return ""; } @@ -435,18 +435,18 @@ bool LMSDevice::setTxAntenna(const std::string & ant, size_t chan) int idx; if (chan >= tx_paths.size()) { - LOG(ALERT) << "Requested non-existent channel " << chan; + LOGC(DDEV, ALERT) << "Requested non-existent channel " << chan; return false; } idx = get_ant_idx(ant, LMS_CH_TX, chan); if (idx < 0) { - LOG(ALERT) << "Invalid Rx Antenna"; + LOGC(DDEV, ALERT) << "Invalid Rx Antenna"; return false; } if (LMS_SetAntenna(m_lms_dev, LMS_CH_TX, chan, idx) < 0) { - LOG(ALERT) << "Unable to set Rx Antenna"; + LOGC(DDEV, ALERT) << "Unable to set Rx Antenna"; } return true; @@ -458,18 +458,18 @@ std::string LMSDevice::getTxAntenna(size_t chan) int idx; if (chan >= tx_paths.size()) { - LOG(ALERT) << "Requested non-existent channel " << chan; + LOGC(DDEV, ALERT) << "Requested non-existent channel " << chan; return ""; } idx = LMS_GetAntenna(m_lms_dev, LMS_CH_TX, chan); if (idx < 0) { - LOG(ALERT) << "Error getting Tx Antenna"; + LOGC(DDEV, ALERT) << "Error getting Tx Antenna"; return ""; } if (LMS_GetAntennaList(m_lms_dev, LMS_CH_TX, chan, name_list) < idx) { - LOG(ALERT) << "Error getting Tx Antenna List"; + LOGC(DDEV, ALERT) << "Error getting Tx Antenna List"; return ""; } @@ -502,7 +502,7 @@ int LMSDevice::readSamples(std::vector < short *>&bufs, int len, bool * overrun, rx_metadata.timestamp = 0; if (bufs.size() != chans) { - LOG(ALERT) << "Invalid channel combination " << bufs.size(); + LOGC(DDEV, ALERT) << "Invalid channel combination " << bufs.size(); return -1; } @@ -512,9 +512,9 @@ int LMSDevice::readSamples(std::vector < short *>&bufs, int len, bool * overrun, thread_enable_cancel(false); rc = LMS_RecvStream(&m_lms_stream_rx[i], bufs[i], len, &rx_metadata, 100); if (timestamp != (TIMESTAMP)rx_metadata.timestamp) - LOG(ALERT) << "chan "<< i << " recv buffer of len " << rc << " expect " << std::hex << timestamp << " got " << std::hex << (TIMESTAMP)rx_metadata.timestamp << " (" << std::hex << rx_metadata.timestamp <<") diff=" << rx_metadata.timestamp - timestamp; + LOGC(DDEV, ALERT) << "chan "<< i << " recv buffer of len " << rc << " expect " << std::hex << timestamp << " got " << std::hex << (TIMESTAMP)rx_metadata.timestamp << " (" << std::hex << rx_metadata.timestamp <<") diff=" << rx_metadata.timestamp - timestamp; if (rc != len) { - LOG(ALERT) << "LMS: Device receive timed out"; + LOGC(DDEV, ALERT) << "LMS: Device receive timed out"; } if (LMS_GetStreamStatus(&m_lms_stream_rx[i], &status) == 0) { @@ -550,23 +550,23 @@ int LMSDevice::writeSamples(std::vector < short *>&bufs, int len, tx_metadata.timestamp = timestamp - ts_offset; /* Shift Tx time by offset */ if (isControl) { - LOG(ERR) << "Control packets not supported"; + LOGC(DDEV, ERR) << "Control packets not supported"; return 0; } if (bufs.size() != chans) { - LOG(ALERT) << "Invalid channel combination " << bufs.size(); + LOGC(DDEV, ALERT) << "Invalid channel combination " << bufs.size(); return -1; } *underrun = false; for (i = 0; i &rx_paths) { if (tx_sps != rx_sps) { - LOG(ERROR) << "LMS Requires tx_sps == rx_sps"; + LOGC(DDEV, ERROR) << "LMS Requires tx_sps == rx_sps"; return NULL; } if (lo_offset != 0.0) { - LOG(ERROR) << "LMS doesn't support lo_offset"; + LOGC(DDEV, ERROR) << "LMS doesn't support lo_offset"; return NULL; } return new LMSDevice(tx_sps, rx_sps, iface, chans, lo_offset, tx_paths, rx_paths); diff --git a/Transceiver52M/device/uhd/UHDDevice.cpp b/Transceiver52M/device/uhd/UHDDevice.cpp index 4af8f87..63d3dec 100644 --- a/Transceiver52M/device/uhd/UHDDevice.cpp +++ b/Transceiver52M/device/uhd/UHDDevice.cpp @@ -340,13 +340,13 @@ void uhd_msg_handler(uhd::msg::type_t type, const std::string &msg) { switch (type) { case uhd::msg::status: - LOG(INFO) << msg; + LOGC(DDEV, INFO) << msg; break; case uhd::msg::warning: - LOG(WARNING) << msg; + LOGC(DDEV, WARNING) << msg; break; case uhd::msg::error: - LOG(ERR) << msg; + LOGC(DDEV, ERR) << msg; break; case uhd::msg::fastpath: break; @@ -388,7 +388,7 @@ void uhd_device::init_gains() if (dev_type == UMTRX) { std::vector gain_stages = usrp_dev->get_tx_gain_names(0); if (gain_stages[0] == "VGA") { - LOG(WARNING) << "Update your UHD version for a proper Tx gain support"; + LOGC(DDEV, WARNING) << "Update your UHD version for a proper Tx gain support"; } if (gain_stages[0] == "VGA" || gain_stages[0] == "PA") { range = usrp_dev->get_tx_gain_range(); @@ -404,23 +404,23 @@ void uhd_device::init_gains() tx_gain_min = range.start(); tx_gain_max = range.stop(); } - LOG(INFO) << "Supported Tx gain range [" << tx_gain_min << "; " << tx_gain_max << "]"; + LOGC(DDEV, INFO) << "Supported Tx gain range [" << tx_gain_min << "; " << tx_gain_max << "]"; range = usrp_dev->get_rx_gain_range(); rx_gain_min = range.start(); rx_gain_max = range.stop(); - LOG(INFO) << "Supported Rx gain range [" << rx_gain_min << "; " << rx_gain_max << "]"; + LOGC(DDEV, INFO) << "Supported Rx gain range [" << rx_gain_min << "; " << rx_gain_max << "]"; for (size_t i = 0; i < tx_gains.size(); i++) { double gain = (tx_gain_min + tx_gain_max) / 2; - LOG(INFO) << "Default setting Tx gain for channel " << i << " to " << gain; + LOGC(DDEV, INFO) << "Default setting Tx gain for channel " << i << " to " << gain; usrp_dev->set_tx_gain(gain, i); tx_gains[i] = usrp_dev->get_tx_gain(i); } for (size_t i = 0; i < rx_gains.size(); i++) { double gain = (rx_gain_min + rx_gain_max) / 2; - LOG(INFO) << "Default setting Rx gain for channel " << i << " to " << gain; + LOGC(DDEV, INFO) << "Default setting Rx gain for channel " << i << " to " << gain; usrp_dev->set_rx_gain(gain, i); rx_gains[i] = usrp_dev->get_rx_gain(i); } @@ -444,7 +444,7 @@ void uhd_device::set_rates() rx_rate = usrp_dev->get_rx_rate(); ts_offset = static_cast(desc.offset * rx_rate); - LOG(INFO) << "Rates configured for " << desc.str; + LOGC(DDEV, INFO) << "Rates configured for " << desc.str; } double uhd_device::setTxGain(double db, size_t chan) @@ -453,7 +453,7 @@ double uhd_device::setTxGain(double db, size_t chan) chan = 0; if (chan >= tx_gains.size()) { - LOG(ALERT) << "Requested non-existent channel" << chan; + LOGC(DDEV, ALERT) << "Requested non-existent channel" << chan; return 0.0f; } @@ -476,7 +476,7 @@ double uhd_device::setTxGain(double db, size_t chan) tx_gains[chan] = usrp_dev->get_tx_gain(chan); - LOG(INFO) << "Set TX gain to " << tx_gains[chan] << "dB (asked for " << db << "dB)"; + LOGC(DDEV, INFO) << "Set TX gain to " << tx_gains[chan] << "dB (asked for " << db << "dB)"; return tx_gains[chan]; } @@ -484,14 +484,14 @@ double uhd_device::setTxGain(double db, size_t chan) double uhd_device::setRxGain(double db, size_t chan) { if (chan >= rx_gains.size()) { - LOG(ALERT) << "Requested non-existent channel " << chan; + LOGC(DDEV, ALERT) << "Requested non-existent channel " << chan; return 0.0f; } usrp_dev->set_rx_gain(db, chan); rx_gains[chan] = usrp_dev->get_rx_gain(chan); - LOG(INFO) << "Set RX gain to " << rx_gains[chan] << "dB (asked for " << db << "dB)"; + LOGC(DDEV, INFO) << "Set RX gain to " << rx_gains[chan] << "dB (asked for " << db << "dB)"; return rx_gains[chan]; } @@ -502,7 +502,7 @@ double uhd_device::getRxGain(size_t chan) chan = 0; if (chan >= rx_gains.size()) { - LOG(ALERT) << "Requested non-existent channel " << chan; + LOGC(DDEV, ALERT) << "Requested non-existent channel " << chan; return 0.0f; } @@ -550,7 +550,7 @@ bool uhd_device::parse_dev_type() mapIter++; } - LOG(ALERT) << "Unsupported device " << devString; + LOGC(DDEV, ALERT) << "Unsupported device " << devString; return false; } @@ -621,16 +621,16 @@ int uhd_device::open(const std::string &args, int ref, bool swap_channels) uhd::device_addr_t addr(args); uhd::device_addrs_t dev_addrs = uhd::device::find(addr); if (dev_addrs.size() == 0) { - LOG(ALERT) << "No UHD devices found with address '" << args << "'"; + LOGC(DDEV, ALERT) << "No UHD devices found with address '" << args << "'"; return -1; } // Use the first found device - LOG(INFO) << "Using discovered UHD device " << dev_addrs[0].to_string(); + LOGC(DDEV, INFO) << "Using discovered UHD device " << dev_addrs[0].to_string(); try { usrp_dev = uhd::usrp::multi_usrp::make(addr); } catch(...) { - LOG(ALERT) << "UHD make failed, device " << args; + LOGC(DDEV, ALERT) << "UHD make failed, device " << args; return -1; } @@ -639,19 +639,19 @@ int uhd_device::open(const std::string &args, int ref, bool swap_channels) return -1; if ((dev_type == E3XX) && !uhd_e3xx_version_chk()) { - LOG(ALERT) << "E3XX requires UHD 003.009.000 or greater"; + LOGC(DDEV, ALERT) << "E3XX requires UHD 003.009.000 or greater"; return -1; } try { set_channels(swap_channels); } catch (const std::exception &e) { - LOG(ALERT) << "Channel setting failed - " << e.what(); + LOGC(DDEV, ALERT) << "Channel setting failed - " << e.what(); return -1; } if (!set_antennas()) { - LOG(ALERT) << "UHD antenna setting failed"; + LOGC(DDEV, ALERT) << "UHD antenna setting failed"; return -1; } @@ -672,7 +672,7 @@ int uhd_device::open(const std::string &args, int ref, bool swap_channels) refstr = "gpsdo"; break; default: - LOG(ALERT) << "Invalid reference type"; + LOGC(DDEV, ALERT) << "Invalid reference type"; return -1; } @@ -681,7 +681,7 @@ int uhd_device::open(const std::string &args, int ref, bool swap_channels) try { set_rates(); } catch (const std::exception &e) { - LOG(ALERT) << "UHD rate setting failed - " << e.what(); + LOGC(DDEV, ALERT) << "UHD rate setting failed - " << e.what(); return -1; } @@ -720,7 +720,7 @@ int uhd_device::open(const std::string &args, int ref, bool swap_channels) init_gains(); // Print configuration - LOG(INFO) << "\n" << usrp_dev->get_pp_string(); + LOGC(DDEV, INFO) << "\n" << usrp_dev->get_pp_string(); if (iface == MULTI_ARFCN) return MULTI_ARFCN; @@ -763,7 +763,7 @@ bool uhd_device::flush_recv(size_t num_pkts) if (!num_smpls) { switch (md.error_code) { case uhd::rx_metadata_t::ERROR_CODE_TIMEOUT: - LOG(ALERT) << "Device timed out"; + LOGC(DDEV, ALERT) << "Device timed out"; return false; default: continue; @@ -773,7 +773,7 @@ bool uhd_device::flush_recv(size_t num_pkts) ts_initial = md.time_spec.to_ticks(rx_rate); } - LOG(INFO) << "Initial timestamp " << ts_initial << std::endl; + LOGC(DDEV, INFO) << "Initial timestamp " << ts_initial << std::endl; return true; } @@ -798,10 +798,10 @@ bool uhd_device::restart() bool uhd_device::start() { - LOG(INFO) << "Starting USRP..."; + LOGC(DDEV, INFO) << "Starting USRP..."; if (started) { - LOG(ERR) << "Device already started"; + LOGC(DDEV, ERR) << "Device already started"; return false; } @@ -819,7 +819,7 @@ bool uhd_device::start() // Display usrp time double time_now = usrp_dev->get_time_now().get_real_secs(); - LOG(INFO) << "The current time is " << time_now << " seconds"; + LOGC(DDEV, INFO) << "The current time is " << time_now << " seconds"; started = true; return true; @@ -852,11 +852,11 @@ void uhd_device::setPriority(float prio) int uhd_device::check_rx_md_err(uhd::rx_metadata_t &md, ssize_t num_smpls) { if (!num_smpls) { - LOG(ERR) << str_code(md); + LOGC(DDEV, ERR) << str_code(md); switch (md.error_code) { case uhd::rx_metadata_t::ERROR_CODE_TIMEOUT: - LOG(ALERT) << "UHD: Receive timed out"; + LOGC(DDEV, ALERT) << "UHD: Receive timed out"; return ERROR_TIMEOUT; case uhd::rx_metadata_t::ERROR_CODE_OVERFLOW: case uhd::rx_metadata_t::ERROR_CODE_LATE_COMMAND: @@ -869,14 +869,14 @@ int uhd_device::check_rx_md_err(uhd::rx_metadata_t &md, ssize_t num_smpls) // Missing timestamp if (!md.has_time_spec) { - LOG(ALERT) << "UHD: Received packet missing timestamp"; + LOGC(DDEV, ALERT) << "UHD: Received packet missing timestamp"; return ERROR_UNRECOVERABLE; } // Monotonicity check if (md.time_spec < prev_ts) { - LOG(ALERT) << "UHD: Loss of monotonic time"; - LOG(ALERT) << "Current time: " << md.time_spec.get_real_secs() << ", " + LOGC(DDEV, ALERT) << "UHD: Loss of monotonic time"; + LOGC(DDEV, ALERT) << "Current time: " << md.time_spec.get_real_secs() << ", " << "Previous time: " << prev_ts.get_real_secs(); return ERROR_TIMING; } @@ -899,7 +899,7 @@ int uhd_device::readSamples(std::vector &bufs, int len, bool *overrun, uhd::rx_metadata_t metadata; if (bufs.size() != chans) { - LOG(ALERT) << "Invalid channel combination " << bufs.size(); + LOGC(DDEV, ALERT) << "Invalid channel combination " << bufs.size(); return -1; } @@ -910,13 +910,13 @@ int uhd_device::readSamples(std::vector &bufs, int len, bool *overrun, timestamp += ts_offset; ts = uhd::time_spec_t::from_ticks(timestamp, rx_rate); - LOG(DEBUG) << "Requested timestamp = " << ts.get_real_secs(); + LOGC(DDEV, DEBUG) << "Requested timestamp = " << ts.get_real_secs(); // Check that timestamp is valid rc = rx_buffers[0]->avail_smpls(timestamp); if (rc < 0) { - LOG(ERR) << rx_buffers[0]->str_code(rc); - LOG(ERR) << rx_buffers[0]->str_status(timestamp); + LOGC(DDEV, ERR) << rx_buffers[0]->str_code(rc); + LOGC(DDEV, ERR) << rx_buffers[0]->str_status(timestamp); return 0; } @@ -941,8 +941,8 @@ int uhd_device::readSamples(std::vector &bufs, int len, bool *overrun, rc = check_rx_md_err(metadata, num_smpls); switch (rc) { case ERROR_UNRECOVERABLE: - LOG(ALERT) << "UHD: Version " << uhd::get_version_string(); - LOG(ALERT) << "UHD: Unrecoverable error, exiting..."; + LOGC(DDEV, ALERT) << "UHD: Version " << uhd::get_version_string(); + LOGC(DDEV, ALERT) << "UHD: Unrecoverable error, exiting..."; exit(-1); case ERROR_TIMEOUT: // Assume stopping condition @@ -954,7 +954,7 @@ int uhd_device::readSamples(std::vector &bufs, int len, bool *overrun, } ts = metadata.time_spec; - LOG(DEBUG) << "Received timestamp = " << ts.get_real_secs(); + LOGC(DDEV, DEBUG) << "Received timestamp = " << ts.get_real_secs(); for (size_t i = 0; i < rx_buffers.size(); i++) { rc = rx_buffers[i]->write((short *) &pkt_bufs[i].front(), @@ -963,8 +963,8 @@ int uhd_device::readSamples(std::vector &bufs, int len, bool *overrun, // Continue on local overrun, exit on other errors if ((rc < 0)) { - LOG(ERR) << rx_buffers[i]->str_code(rc); - LOG(ERR) << rx_buffers[i]->str_status(timestamp); + LOGC(DDEV, ERR) << rx_buffers[i]->str_code(rc); + LOGC(DDEV, ERR) << rx_buffers[i]->str_status(timestamp); if (rc != smpl_buf::ERROR_OVERFLOW) return 0; } @@ -975,8 +975,8 @@ int uhd_device::readSamples(std::vector &bufs, int len, bool *overrun, for (size_t i = 0; i < rx_buffers.size(); i++) { rc = rx_buffers[i]->read(bufs[i], len, timestamp); if ((rc < 0) || (rc != len)) { - LOG(ERR) << rx_buffers[i]->str_code(rc); - LOG(ERR) << rx_buffers[i]->str_status(timestamp); + LOGC(DDEV, ERR) << rx_buffers[i]->str_code(rc); + LOGC(DDEV, ERR) << rx_buffers[i]->str_status(timestamp); return 0; } } @@ -997,12 +997,12 @@ int uhd_device::writeSamples(std::vector &bufs, int len, bool *underrun // No control packets if (isControl) { - LOG(ERR) << "Control packets not supported"; + LOGC(DDEV, ERR) << "Control packets not supported"; return 0; } if (bufs.size() != chans) { - LOG(ALERT) << "Invalid channel combination " << bufs.size(); + LOGC(DDEV, ALERT) << "Invalid channel combination " << bufs.size(); return -1; } @@ -1011,14 +1011,14 @@ int uhd_device::writeSamples(std::vector &bufs, int len, bool *underrun drop_cnt++; if (drop_cnt == 1) { - LOG(DEBUG) << "Aligning transmitter: stop burst"; + LOGC(DDEV, DEBUG) << "Aligning transmitter: stop burst"; *underrun = true; metadata.end_of_burst = true; } else if (drop_cnt < 30) { - LOG(DEBUG) << "Aligning transmitter: packet advance"; + LOGC(DDEV, DEBUG) << "Aligning transmitter: packet advance"; return len; } else { - LOG(DEBUG) << "Aligning transmitter: start burst"; + LOGC(DDEV, DEBUG) << "Aligning transmitter: start burst"; metadata.start_of_burst = true; aligned = true; drop_cnt = 0; @@ -1030,7 +1030,7 @@ int uhd_device::writeSamples(std::vector &bufs, int len, bool *underrun thread_enable_cancel(true); if (num_smpls != (unsigned) len) { - LOG(ALERT) << "UHD: Device send timed out"; + LOGC(DDEV, ALERT) << "UHD: Device send timed out"; } return num_smpls; @@ -1066,7 +1066,7 @@ uhd::tune_request_t uhd_device::select_freq(double freq, size_t chan, bool tx) return uhd::tune_request_t(freq, lo_offset); } else if ((dev_type != B210) || (chans > 2) || (chan > 1)) { - LOG(ALERT) << chans << " channels unsupported"; + LOGC(DDEV, ALERT) << chans << " channels unsupported"; return treq; } @@ -1082,7 +1082,7 @@ uhd::tune_request_t uhd_device::select_freq(double freq, size_t chan, bool tx) /* Find center frequency between channels */ rf_spread = fabs(freqs[!chan] - freq); if (rf_spread > dev_param_map.at(dev_key(B210, tx_sps, rx_sps)).mcr) { - LOG(ALERT) << rf_spread << "Hz tuning spread not supported\n"; + LOGC(DDEV, ALERT) << rf_spread << "Hz tuning spread not supported\n"; return treq; } @@ -1108,7 +1108,7 @@ bool uhd_device::set_freq(double freq, size_t chan, bool tx) tres = usrp_dev->set_rx_freq(treq, chan); rx_freqs[chan] = usrp_dev->get_rx_freq(chan); } - LOG(INFO) << "\n" << tres.to_pp_string() << std::endl; + LOGC(DDEV, INFO) << "\n" << tres.to_pp_string() << std::endl; if ((chans == 1) || ((chans == 2) && dev_type == UMTRX)) return true; @@ -1128,7 +1128,7 @@ bool uhd_device::set_freq(double freq, size_t chan, bool tx) rx_freqs[!chan] = usrp_dev->get_rx_freq(!chan); } - LOG(INFO) << "\n" << tres.to_pp_string() << std::endl; + LOGC(DDEV, INFO) << "\n" << tres.to_pp_string() << std::endl; } return true; @@ -1137,7 +1137,7 @@ bool uhd_device::set_freq(double freq, size_t chan, bool tx) bool uhd_device::setTxFreq(double wFreq, size_t chan) { if (chan >= tx_freqs.size()) { - LOG(ALERT) << "Requested non-existent channel " << chan; + LOGC(DDEV, ALERT) << "Requested non-existent channel " << chan; return false; } ScopedLock lock(tune_lock); @@ -1148,7 +1148,7 @@ bool uhd_device::setTxFreq(double wFreq, size_t chan) bool uhd_device::setRxFreq(double wFreq, size_t chan) { if (chan >= rx_freqs.size()) { - LOG(ALERT) << "Requested non-existent channel " << chan; + LOGC(DDEV, ALERT) << "Requested non-existent channel " << chan; return false; } ScopedLock lock(tune_lock); @@ -1159,7 +1159,7 @@ bool uhd_device::setRxFreq(double wFreq, size_t chan) double uhd_device::getTxFreq(size_t chan) { if (chan >= tx_freqs.size()) { - LOG(ALERT) << "Requested non-existent channel " << chan; + LOGC(DDEV, ALERT) << "Requested non-existent channel " << chan; return 0.0; } @@ -1169,7 +1169,7 @@ double uhd_device::getTxFreq(size_t chan) double uhd_device::getRxFreq(size_t chan) { if (chan >= rx_freqs.size()) { - LOG(ALERT) << "Requested non-existent channel " << chan; + LOGC(DDEV, ALERT) << "Requested non-existent channel " << chan; return 0.0; } @@ -1180,23 +1180,23 @@ bool uhd_device::setRxAntenna(const std::string &ant, size_t chan) { std::vector avail; if (chan >= rx_paths.size()) { - LOG(ALERT) << "Requested non-existent channel " << chan; + LOGC(DDEV, ALERT) << "Requested non-existent channel " << chan; return false; } avail = usrp_dev->get_rx_antennas(chan); if (std::find(avail.begin(), avail.end(), ant) == avail.end()) { - LOG(ALERT) << "Requested non-existent Rx antenna " << ant << " on channel " << chan; - LOG(INFO) << "Available Rx antennas: "; + LOGC(DDEV, ALERT) << "Requested non-existent Rx antenna " << ant << " on channel " << chan; + LOGC(DDEV, INFO) << "Available Rx antennas: "; for (std::vector::const_iterator i = avail.begin(); i != avail.end(); ++i) - LOG(INFO) << "- '" << *i << "'"; + LOGC(DDEV, INFO) << "- '" << *i << "'"; return false; } usrp_dev->set_rx_antenna(ant, chan); rx_paths[chan] = usrp_dev->get_rx_antenna(chan); if (ant != rx_paths[chan]) { - LOG(ALERT) << "Failed setting antenna " << ant << " on channel " << chan << ", got instead " << rx_paths[chan]; + LOGC(DDEV, ALERT) << "Failed setting antenna " << ant << " on channel " << chan << ", got instead " << rx_paths[chan]; return false; } @@ -1206,7 +1206,7 @@ bool uhd_device::setRxAntenna(const std::string &ant, size_t chan) std::string uhd_device::getRxAntenna(size_t chan) { if (chan >= rx_paths.size()) { - LOG(ALERT) << "Requested non-existent channel " << chan; + LOGC(DDEV, ALERT) << "Requested non-existent channel " << chan; return ""; } return usrp_dev->get_rx_antenna(chan); @@ -1216,23 +1216,23 @@ bool uhd_device::setTxAntenna(const std::string &ant, size_t chan) { std::vector avail; if (chan >= tx_paths.size()) { - LOG(ALERT) << "Requested non-existent channel " << chan; + LOGC(DDEV, ALERT) << "Requested non-existent channel " << chan; return false; } avail = usrp_dev->get_tx_antennas(chan); if (std::find(avail.begin(), avail.end(), ant) == avail.end()) { - LOG(ALERT) << "Requested non-existent Tx antenna " << ant << " on channel " << chan; - LOG(INFO) << "Available Tx antennas: "; + LOGC(DDEV, ALERT) << "Requested non-existent Tx antenna " << ant << " on channel " << chan; + LOGC(DDEV, INFO) << "Available Tx antennas: "; for (std::vector::const_iterator i = avail.begin(); i != avail.end(); ++i) - LOG(INFO) << "- '" << *i << "'"; + LOGC(DDEV, INFO) << "- '" << *i << "'"; return false; } usrp_dev->set_tx_antenna(ant, chan); tx_paths[chan] = usrp_dev->get_tx_antenna(chan); if (ant != tx_paths[chan]) { - LOG(ALERT) << "Failed setting antenna " << ant << " on channel " << chan << ", got instead " << tx_paths[chan]; + LOGC(DDEV, ALERT) << "Failed setting antenna " << ant << " on channel " << chan << ", got instead " << tx_paths[chan]; return false; } @@ -1242,7 +1242,7 @@ bool uhd_device::setTxAntenna(const std::string &ant, size_t chan) std::string uhd_device::getTxAntenna(size_t chan) { if (chan >= tx_paths.size()) { - LOG(ALERT) << "Requested non-existent channel " << chan; + LOGC(DDEV, ALERT) << "Requested non-existent channel " << chan; return ""; } return usrp_dev->get_tx_antenna(chan); @@ -1310,7 +1310,7 @@ bool uhd_device::recv_async_msg() if ((md.event_code != uhd::async_metadata_t::EVENT_CODE_UNDERFLOW) && (md.event_code != uhd::async_metadata_t::EVENT_CODE_TIME_ERROR)) { - LOG(ERR) << str_code(md); + LOGC(DDEV, ERR) << str_code(md); } } @@ -1470,15 +1470,15 @@ ssize_t smpl_buf::write(void *buf, size_t len, TIMESTAMP timestamp) return ERROR_TIMESTAMP; if (timestamp < time_end) { - LOG(ERR) << "Overwriting old buffer data: timestamp="<fpga_master_clock_freq() != masterClockRate) { - LOG(ALERT) << "WRONG FPGA clock freq = " << m_uRx->fpga_master_clock_freq() + LOGC(DDEV, ALERT) << "WRONG FPGA clock freq = " << m_uRx->fpga_master_clock_freq() << ", desired clock freq = " << masterClockRate; m_uRx.reset(); return -1; @@ -132,14 +132,14 @@ int USRPDevice::open(const std::string &, int, bool) } catch(...) { - LOG(ALERT) << "make failed on Tx"; + LOGC(DDEV, ALERT) << "make failed on Tx"; m_uTx.reset(); return -1; } if (m_uTx->fpga_master_clock_freq() != masterClockRate) { - LOG(ALERT) << "WRONG FPGA clock freq = " << m_uTx->fpga_master_clock_freq() + LOGC(DDEV, ALERT) << "WRONG FPGA clock freq = " << m_uTx->fpga_master_clock_freq() << ", desired clock freq = " << masterClockRate; m_uTx.reset(); return -1; @@ -186,7 +186,7 @@ int USRPDevice::open(const std::string &, int, bool) bool USRPDevice::start() { - LOG(INFO) << "starting USRP..."; + LOGC(DDEV, INFO) << "starting USRP..."; #ifndef SWLOOPBACK if (!m_uRx && !skipRx) return false; if (!m_uTx) return false; @@ -270,7 +270,7 @@ double USRPDevice::minRxGain() double USRPDevice::setTxGain(double dB, size_t chan) { if (chan) { - LOG(ALERT) << "Invalid channel " << chan; + LOGC(DDEV, ALERT) << "Invalid channel " << chan; return 0.0; } @@ -280,10 +280,10 @@ double USRPDevice::setTxGain(double dB, size_t chan) if (dB < minTxGain()) dB = minTxGain(); - LOG(NOTICE) << "Setting TX gain to " << dB << " dB."; + LOGC(DDEV, NOTICE) << "Setting TX gain to " << dB << " dB."; if (!m_dbTx->set_gain(dB)) - LOG(ERR) << "Error setting TX gain"; + LOGC(DDEV, ERR) << "Error setting TX gain"; writeLock.unlock(); @@ -294,7 +294,7 @@ double USRPDevice::setTxGain(double dB, size_t chan) double USRPDevice::setRxGain(double dB, size_t chan) { if (chan) { - LOG(ALERT) << "Invalid channel " << chan; + LOGC(DDEV, ALERT) << "Invalid channel " << chan; return 0.0; } @@ -306,10 +306,10 @@ double USRPDevice::setRxGain(double dB, size_t chan) if (dB < minRxGain()) dB = minRxGain(); - LOG(NOTICE) << "Setting RX gain to " << dB << " dB."; + LOGC(DDEV, NOTICE) << "Setting RX gain to " << dB << " dB."; if (!m_dbRx->set_gain(dB)) - LOG(ERR) << "Error setting RX gain"; + LOGC(DDEV, ERR) << "Error setting RX gain"; writeLock.unlock(); @@ -319,40 +319,40 @@ double USRPDevice::setRxGain(double dB, size_t chan) bool USRPDevice::setRxAntenna(const std::string &ant, size_t chan) { if (chan >= rx_paths.size()) { - LOG(ALERT) << "Requested non-existent channel " << chan; + LOGC(DDEV, ALERT) << "Requested non-existent channel " << chan; return false; } - LOG(ALERT) << "Not implemented"; + LOGC(DDEV, ALERT) << "Not implemented"; return true; } std::string USRPDevice::getRxAntenna(size_t chan) { if (chan >= rx_paths.size()) { - LOG(ALERT) << "Requested non-existent channel " << chan; + LOGC(DDEV, ALERT) << "Requested non-existent channel " << chan; return ""; } - LOG(ALERT) << "Not implemented"; + LOGC(DDEV, ALERT) << "Not implemented"; return ""; } bool USRPDevice::setTxAntenna(const std::string &ant, size_t chan) { if (chan >= tx_paths.size()) { - LOG(ALERT) << "Requested non-existent channel " << chan; + LOGC(DDEV, ALERT) << "Requested non-existent channel " << chan; return false; } - LOG(ALERT) << "Not implemented"; + LOGC(DDEV, ALERT) << "Not implemented"; return true; } std::string USRPDevice::getTxAntenna(size_t chan) { if (chan >= tx_paths.size()) { - LOG(ALERT) << "Requested non-existent channel " << chan; + LOGC(DDEV, ALERT) << "Requested non-existent channel " << chan; return ""; } - LOG(ALERT) << "Not implemented"; + LOGC(DDEV, ALERT) << "Not implemented"; return ""; } @@ -405,11 +405,11 @@ int USRPDevice::readSamples(std::vector &bufs, int len, bool *overrun, uint32_t word0 = usrp_to_host_u32(tmpBuf[0]); uint32_t chan = (word0 >> 16) & 0x1f; unsigned payloadSz = word0 & 0x1ff; - LOG(DEBUG) << "first two bytes: " << hex << word0 << " " << dec << pktTimestamp; + LOGC(DDEV, DEBUG) << "first two bytes: " << hex << word0 << " " << dec << pktTimestamp; bool incrementHi32 = ((lastPktTimestamp & 0x0ffffffffll) > pktTimestamp); if (incrementHi32 && (timeStart!=0)) { - LOG(DEBUG) << "high 32 increment!!!"; + LOGC(DDEV, DEBUG) << "high 32 increment!!!"; hi32Timestamp++; } pktTimestamp = (((TIMESTAMP) hi32Timestamp) << 32) | pktTimestamp; @@ -421,19 +421,19 @@ int USRPDevice::readSamples(std::vector &bufs, int len, bool *overrun, if ((word2 >> 16) == ((0x01 << 8) | 0x02)) { timestamp -= timestampOffset; timestampOffset = pktTimestamp - pingTimestamp + pingOffset; - LOG(DEBUG) << "updating timestamp offset to: " << timestampOffset; + LOGC(DDEV, DEBUG) << "updating timestamp offset to: " << timestampOffset; timestamp += timestampOffset; isAligned = true; } continue; } if (chan != 0) { - LOG(DEBUG) << "chan: " << chan << ", timestamp: " << pktTimestamp << ", sz:" << payloadSz; + LOGC(DDEV, DEBUG) << "chan: " << chan << ", timestamp: " << pktTimestamp << ", sz:" << payloadSz; continue; } if ((word0 >> 28) & 0x04) { if (underrun) *underrun = true; - LOG(DEBUG) << "UNDERRUN in TRX->USRP interface"; + LOGC(DDEV, DEBUG) << "UNDERRUN in TRX->USRP interface"; } if (RSSI) *RSSI = (word0 >> 21) & 0x3f; @@ -454,7 +454,7 @@ int USRPDevice::readSamples(std::vector &bufs, int len, bool *overrun, if (pktTimestamp + payloadSz/2/sizeof(short) > timeEnd) timeEnd = pktTimestamp+payloadSz/2/sizeof(short); - LOG(DEBUG) << "timeStart: " << timeStart << ", timeEnd: " << timeEnd << ", pktTimestamp: " << pktTimestamp; + LOGC(DDEV, DEBUG) << "timeStart: " << timeStart << ", timeEnd: " << timeEnd << ", pktTimestamp: " << pktTimestamp; } } @@ -462,14 +462,14 @@ int USRPDevice::readSamples(std::vector &bufs, int len, bool *overrun, // copy desired data to buf unsigned bufStart = dataStart+(timestamp-timeStart); if (bufStart + len < currDataSize/2) { - LOG(DEBUG) << "bufStart: " << bufStart; + LOGC(DDEV, DEBUG) << "bufStart: " << bufStart; memcpy(buf,data+bufStart*2,len*2*sizeof(short)); memset(data+bufStart*2,0,len*2*sizeof(short)); } else { - LOG(DEBUG) << "len: " << len << ", currDataSize/2: " << currDataSize/2 << ", bufStart: " << bufStart; + LOGC(DDEV, DEBUG) << "len: " << len << ", currDataSize/2: " << currDataSize/2 << ", bufStart: " << bufStart; unsigned firstLength = (currDataSize/2-bufStart); - LOG(DEBUG) << "firstLength: " << firstLength; + LOGC(DDEV, DEBUG) << "firstLength: " << firstLength; memcpy(buf,data+bufStart*2,firstLength*2*sizeof(short)); memset(data+bufStart*2,0,firstLength*2*sizeof(short)); memcpy(buf+firstLength*2,data,(len-firstLength)*2*sizeof(short)); @@ -599,19 +599,19 @@ bool USRPDevice::setTxFreq(double wFreq, size_t chan) usrp_tune_result result; if (chan) { - LOG(ALERT) << "Invalid channel " << chan; + LOGC(DDEV, ALERT) << "Invalid channel " << chan; return false; } if (m_uTx->tune(txSubdevSpec.side, m_dbTx, wFreq, &result)) { - LOG(INFO) << "set TX: " << wFreq << std::endl + LOGC(DDEV, INFO) << "set TX: " << wFreq << std::endl << " baseband freq: " << result.baseband_freq << std::endl << " DDC freq: " << result.dxc_freq << std::endl << " residual freq: " << result.residual_freq; return true; } else { - LOG(ALERT) << "set TX: " << wFreq << "failed" << std::endl + LOGC(DDEV, ALERT) << "set TX: " << wFreq << "failed" << std::endl << " baseband freq: " << result.baseband_freq << std::endl << " DDC freq: " << result.dxc_freq << std::endl << " residual freq: " << result.residual_freq; @@ -624,19 +624,19 @@ bool USRPDevice::setRxFreq(double wFreq, size_t chan) usrp_tune_result result; if (chan) { - LOG(ALERT) << "Invalid channel " << chan; + LOGC(DDEV, ALERT) << "Invalid channel " << chan; return false; } if (m_uRx->tune(0, m_dbRx, wFreq, &result)) { - LOG(INFO) << "set RX: " << wFreq << std::endl + LOGC(DDEV, INFO) << "set RX: " << wFreq << std::endl << " baseband freq: " << result.baseband_freq << std::endl << " DDC freq: " << result.dxc_freq << std::endl << " residual freq: " << result.residual_freq; return true; } else { - LOG(ALERT) << "set RX: " << wFreq << "failed" << std::endl + LOGC(DDEV, ALERT) << "set RX: " << wFreq << "failed" << std::endl << " baseband freq: " << result.baseband_freq << std::endl << " DDC freq: " << result.dxc_freq << std::endl << " residual freq: " << result.residual_freq; @@ -656,15 +656,15 @@ RadioDevice *RadioDevice::make(size_t tx_sps, size_t rx_sps, const std::vector& rx_paths) { if (tx_sps != rx_sps) { - LOG(ERROR) << "USRP1 requires tx_sps == rx_sps"; + LOGC(DDEV, ERROR) << "USRP1 requires tx_sps == rx_sps"; return NULL; } if (chans != 1) { - LOG(ERROR) << "USRP1 supports only 1 channel"; + LOGC(DDEV, ERROR) << "USRP1 supports only 1 channel"; return NULL; } if (lo_offset != 0.0) { - LOG(ERROR) << "USRP1 doesn't support lo_offset"; + LOGC(DDEV, ERROR) << "USRP1 doesn't support lo_offset"; return NULL; } return new USRPDevice(tx_sps, rx_sps, iface, chans, lo_offset, tx_paths, rx_paths); -- cgit v1.2.3