diff options
author | Marcus Müller <mmueller@gnuradio.org> | 2020-04-11 00:43:39 +0200 |
---|---|---|
committer | Marcus Müller <marcus@hostalia.de> | 2020-04-13 15:55:41 +0200 |
commit | 0f88db1ef0569bf6fcd5e9c843da38d487a6f54b (patch) | |
tree | 4c9827377c0e98fe223f39edb0c84c8a49c199e9 | |
parent | ec8a92846a388cb0d2982822ea1961910cd552f8 (diff) |
runtime: replace stderr logging by calls to GR's logging facilties
26 files changed, 354 insertions, 220 deletions
diff --git a/gnuradio-runtime/apps/gnuradio-config-info.cc b/gnuradio-runtime/apps/gnuradio-config-info.cc index f2f6580e94..1e73605f72 100644 --- a/gnuradio-runtime/apps/gnuradio-config-info.cc +++ b/gnuradio-runtime/apps/gnuradio-config-info.cc @@ -13,6 +13,7 @@ #endif #include <gnuradio/constants.h> +#include <gnuradio/logger.h> #include <gnuradio/prefs.h> #include <gnuradio/sys_paths.h> #include <boost/format.hpp> @@ -44,8 +45,9 @@ int main(int argc, char** argv) po::store(po::parse_command_line(argc, argv, desc), vm); po::notify(vm); } catch (po::error& error) { - std::cerr << "Error: " << error.what() << std::endl << std::endl; - std::cerr << desc << std::endl; + gr::logger_ptr logger, debug_logger; + gr::configure_default_loggers(logger, debug_logger, "gnuradio-config-info.cc"); + GR_LOG_ERROR(logger, boost::format("ERROR %s %s") % error.what() % desc); return 1; } diff --git a/gnuradio-runtime/include/gnuradio/block_detail.h b/gnuradio-runtime/include/gnuradio/block_detail.h index 7f625e6d27..454945f0f5 100644 --- a/gnuradio-runtime/include/gnuradio/block_detail.h +++ b/gnuradio-runtime/include/gnuradio/block_detail.h @@ -13,6 +13,7 @@ #include <gnuradio/api.h> #include <gnuradio/high_res_timer.h> +#include <gnuradio/logger.h> #include <gnuradio/runtime_types.h> #include <gnuradio/tags.h> #include <gnuradio/tpb_detail.h> @@ -232,6 +233,10 @@ public: int consumed() const; + // necessary because stupidly block_executor.cc's "propagate_tags" is a function, not + // any class member + gr::logger_ptr d_logger, d_debug_logger; + // ---------------------------------------------------------------------------- private: diff --git a/gnuradio-runtime/include/gnuradio/buffer.h b/gnuradio-runtime/include/gnuradio/buffer.h index cb4ac42e28..ef673bf500 100644 --- a/gnuradio-runtime/include/gnuradio/buffer.h +++ b/gnuradio-runtime/include/gnuradio/buffer.h @@ -12,9 +12,11 @@ #define INCLUDED_GR_RUNTIME_BUFFER_H #include <gnuradio/api.h> +#include <gnuradio/logger.h> #include <gnuradio/runtime_types.h> #include <gnuradio/tags.h> #include <gnuradio/thread/thread.h> +#include <boost/weak_ptr.hpp> #include <map> #include <memory> @@ -44,6 +46,9 @@ GR_RUNTIME_API buffer_sptr make_buffer(int nitems, class GR_RUNTIME_API buffer { public: + gr::logger_ptr d_logger; + gr::logger_ptr d_debug_logger; + virtual ~buffer(); /*! diff --git a/gnuradio-runtime/include/gnuradio/rpcserver_thrift.h b/gnuradio-runtime/include/gnuradio/rpcserver_thrift.h index 2c4d75a29e..1271590611 100644 --- a/gnuradio-runtime/include/gnuradio/rpcserver_thrift.h +++ b/gnuradio-runtime/include/gnuradio/rpcserver_thrift.h @@ -13,6 +13,7 @@ #include "thrift/ControlPort.h" #include "thrift/gnuradio_types.h" +#include <gnuradio/logger.h> #include <gnuradio/rpcpmtconverters_thrift.h> #include <gnuradio/rpcserver_base.h> #include <boost/format.hpp> @@ -29,6 +30,9 @@ class rpcserver_thrift : public virtual rpcserver_base, public GNURadio::ControlPortIf { public: + gr::logger_ptr d_logger; + gr::logger_ptr d_debug_logger; + rpcserver_thrift(); virtual ~rpcserver_thrift(); @@ -100,9 +104,11 @@ private: if (cur_priv <= _handlerCallback.priv) { _handlerCallback.callback->post(port, msg); } else { - std::cerr << "Message " << _handlerCallback.description - << " requires PRIVLVL <= " << _handlerCallback.priv - << " to set, currently at: " << cur_priv << std::endl; + std::ostringstream msg; + msg << _handlerCallback.description + << " requires PRIVLVL <= " << _handlerCallback.priv + << " to set, currently at: " << cur_priv; + GR_LOG_ERROR(logger, msg.str()); } } @@ -123,9 +129,11 @@ private: (*iter->second.callback) .post(pmt::PMT_NIL, rpcpmtconverter::To_PMT::instance(p.second)); } else { - std::cerr << "Key " << p.first - << " requires PRIVLVL <= " << iter->second.priv - << " to set, currently at: " << cur_priv << std::endl; + std::ostringstream msg; + msg << "Key " << p.first + << " requires PRIVLVL <= " << iter->second.priv + << " to set, currently at: " << cur_priv; + GR_LOG_ERROR(logger, msg.str()); } } else { throw apache::thrift::TApplicationException(__FILE__ " " S__LINE__); @@ -153,14 +161,16 @@ private: outknobs[p] = rpcpmtconverter::from_pmt((*iter->second.callback).retrieve()); } else { - std::cerr << "Key " << iter->first - << " requires PRIVLVL: <= " << iter->second.priv - << " to get, currently at: " << cur_priv << std::endl; + std::ostringstream msg; + msg << "Key " << iter->first + << " requires PRIVLVL: <= " << iter->second.priv + << " to get, currently at: " << cur_priv; + GR_LOG_ERROR(logger, msg.str()); } } else { - std::stringstream ss; - ss << "Ctrlport Key called with unregistered key (" << p << ")\n"; - std::cerr << ss.str(); + std::ostringstream smsgs; + msg << "Ctrlport Key called with unregistered key (" << p << ")\n"; + GR_LOG_ERROR(logger, ss.str()); throw apache::thrift::TApplicationException(__FILE__ " " S__LINE__); } } @@ -184,8 +194,10 @@ private: outknobs[p.first] = rpcpmtconverter::from_pmt(p.second.callback->retrieve()); } else { - std::cerr << "Key " << p.first << " requires PRIVLVL <= " << p.second.priv - << " to get, currently at: " << cur_priv << std::endl; + std::ostringstream msg; + msg << "Key " << p.first << " requires PRIVLVL: <= " << p.second.priv + << " to get, currently at: " << cur_priv; + GR_LOG_ERROR(logger, msg.str()); } } @@ -216,8 +228,10 @@ private: prop.display = static_cast<uint32_t>(p.second.display); outknobs[p.first] = prop; } else { - std::cerr << "Key " << p.first << " requires PRIVLVL <= " << p.second.priv - << " to get, currently at: " << cur_priv << std::endl; + std::ostringstream msg; + msg << "Key " << p.first << " requires PRIVLVL: <= " << p.second.priv + << " to get, currently at: " << cur_priv; + GR_LOG_ERROR(logger, msg.str()); } } @@ -250,9 +264,11 @@ private: prop.display = static_cast<uint32_t>(iter->second.display); outknobs[p] = prop; } else { - std::cerr << "Key " << iter->first - << " requires PRIVLVL: <= " << iter->second.priv - << " to get, currently at: " << cur_priv << std::endl; + std::ostringstream msg; + msg << "Key " << iter->first + << " requires PRIVLVL: <= " << iter->second.priv + << " to get, currently at: " << cur_priv; + GR_LOG_ERROR(logger, msg.str()); } } else { throw apache::thrift::TApplicationException(__FILE__ " " S__LINE__); diff --git a/gnuradio-runtime/include/gnuradio/thread/thread_body_wrapper.h b/gnuradio-runtime/include/gnuradio/thread/thread_body_wrapper.h index fe611e8b13..98d74f1420 100644 --- a/gnuradio-runtime/include/gnuradio/thread/thread_body_wrapper.h +++ b/gnuradio-runtime/include/gnuradio/thread/thread_body_wrapper.h @@ -12,6 +12,7 @@ #define INCLUDED_THREAD_BODY_WRAPPER_H #include <gnuradio/api.h> +#include <gnuradio/logger.h> #include <gnuradio/thread/thread.h> #include <exception> #include <iostream> @@ -28,6 +29,8 @@ private: F d_f; std::string d_name; bool d_catch_exceptions; + gr::logger_ptr d_logger; + gr::logger_ptr d_debug_logger; public: explicit thread_body_wrapper(F f, @@ -35,6 +38,7 @@ public: bool catch_exceptions = true) : d_f(f), d_name(name), d_catch_exceptions(catch_exceptions) { + gr::configure_default_loggers(d_logger, d_debug_logger, "thread_body_wrapper"); } void operator()() @@ -46,10 +50,13 @@ public: d_f(); } catch (boost::thread_interrupted const&) { } catch (std::exception const& e) { - std::cerr << "thread[" << d_name << "]: " << e.what() << std::endl; + std::ostringstream msg; + msg << "ERROR thread[" << d_name << "]: " << e.what(); + GR_LOG_ERROR(d_logger, msg.str()); } catch (...) { - std::cerr << "thread[" << d_name << "]: " - << "caught unrecognized exception\n"; + std::ostringstream msg; + msg << "ERROR thread[" << d_name << "]: caught unrecognized exception"; + GR_LOG_ERROR(d_logger, msg.str()); } } else { diff --git a/gnuradio-runtime/lib/block_detail.cc b/gnuradio-runtime/lib/block_detail.cc index 534acb3a8e..ca8b9fd6ac 100644 --- a/gnuradio-runtime/lib/block_detail.cc +++ b/gnuradio-runtime/lib/block_detail.cc @@ -14,6 +14,7 @@ #include <gnuradio/block_detail.h> #include <gnuradio/buffer.h> +#include <gnuradio/logger.h> #include <iostream> namespace gr { @@ -50,6 +51,7 @@ block_detail::block_detail(unsigned int ninputs, unsigned int noutputs) { s_ncurrently_allocated++; d_pc_start_time = gr::high_res_timer_now(); + gr::configure_default_loggers(d_logger, d_debug_logger, "block_detail"); } block_detail::~block_detail() @@ -220,7 +222,7 @@ void block_detail::set_processor_affinity(const std::vector<int>& mask) try { gr::thread::thread_bind_to_processor(thread, mask); } catch (std::runtime_error& e) { - std::cerr << "set_processor_affinity: invalid mask." << std::endl; + GR_LOG_ERROR(d_logger, "set_processor_affinity: invalid mask."); } } } diff --git a/gnuradio-runtime/lib/block_executor.cc b/gnuradio-runtime/lib/block_executor.cc index d4c98e1225..322c7041b5 100644 --- a/gnuradio-runtime/lib/block_executor.cc +++ b/gnuradio-runtime/lib/block_executor.cc @@ -15,6 +15,7 @@ #include <gnuradio/block.h> #include <gnuradio/block_detail.h> #include <gnuradio/buffer.h> +#include <gnuradio/logger.h> #include <gnuradio/prefs.h> #include <assert.h> #include <block_executor.h> @@ -42,8 +43,6 @@ namespace gr { } while (0) #endif -static int which_scheduler = 0; - inline static unsigned int round_up(unsigned int n, unsigned int multiple) { return ((n + multiple - 1) / multiple) * multiple; @@ -201,9 +200,10 @@ static bool propagate_tags(block::tag_propagation_policy_t policy, } } } else { - std::cerr << "Error: block_executor: propagation_policy 'ONE-TO-ONE' " - "requires ninputs == noutputs" - << std::endl; + std::ostringstream msg; + msg << "block_executor: propagation_policy 'ONE-TO-ONE'"; + msg << " requires ninputs == noutputs"; + GR_LOG_ERROR(d->d_logger, msg.str()); return false; } break; @@ -216,12 +216,7 @@ static bool propagate_tags(block::tag_propagation_policy_t policy, block_executor::block_executor(block_sptr block, int max_noutput_items) : d_block(block), d_max_noutput_items(max_noutput_items) { - if (ENABLE_LOGGING) { - std::string name = str(boost::format("sst-%03d.log") % which_scheduler++); - d_log = boost::make_unique<std::ofstream>(name.c_str()); - std::unitbuf(*d_log); // make it unbuffered... - *d_log << "block_executor: " << d_block << std::endl; - } + gr::configure_default_loggers(d_logger, d_debug_logger, "block_executor"); #ifdef GR_PERFORMANCE_COUNTERS prefs* prefs = prefs::singleton(); @@ -247,7 +242,7 @@ block_executor::state block_executor::run_one_iteration() block* m = d_block.get(); block_detail* d = m->detail().get(); - LOG(*d_log << std::endl << m); + LOG(std::ostringstream msg; msg << m; GR_LOG_INFO(d_debug_logger, msg.str());); max_noutput_items = round_down(d_max_noutput_items, m->output_multiple()); @@ -268,12 +263,13 @@ block_executor::state block_executor::run_one_iteration() noutput_items = min_available_space(d, m->output_multiple(), m->min_noutput_items()); noutput_items = std::min(noutput_items, max_noutput_items); - LOG(*d_log << " source\n noutput_items = " << noutput_items << std::endl); + LOG(std::ostringstream msg; msg << "source: noutput_items = " << noutput_items; + GR_LOG_INFO(d_debug_logger, msg.str());); if (noutput_items == -1) // we're done goto were_done; if (noutput_items == 0) { // we're output blocked - LOG(*d_log << " BLKD_OUT\n"); + LOG(GR_LOG_INFO(d_debug_logger, "BLKD_OUT");); return BLKD_OUT; } @@ -287,7 +283,7 @@ block_executor::state block_executor::run_one_iteration() d_input_done.resize(d->ninputs()); d_output_items.resize(0); d_start_nitems_read.resize(d->ninputs()); - LOG(*d_log << " sink\n"); + LOG(GR_LOG_INFO(d_debug_logger, "sink");); max_items_avail = 0; for (int i = 0; i < d->ninputs(); i++) { @@ -301,10 +297,12 @@ block_executor::state block_executor::run_one_iteration() d_input_done[i] = in_buf->done(); } - LOG(*d_log << " d_ninput_items[" << i << "] = " << d_ninput_items[i] - << std::endl); - LOG(*d_log << " d_input_done[" << i << "] = " << d_input_done[i] - << std::endl); + LOG(std::ostringstream msg; + msg << "d_ninput_items[" << i << "] = " << d_ninput_items[i]; + GR_LOG_INFO(d_debug_logger, msg.str());); + LOG(std::ostringstream msg; + msg << "d_input_done[" << i << "] = " << d_input_done[i]; + GR_LOG_INFO(d_debug_logger, msg.str());); if (d_ninput_items[i] < m->output_multiple() && d_input_done[i]) goto were_done; @@ -316,11 +314,13 @@ block_executor::state block_executor::run_one_iteration() noutput_items = (int)(max_items_avail * m->relative_rate()); noutput_items = round_down(noutput_items, m->output_multiple()); noutput_items = std::min(noutput_items, max_noutput_items); - LOG(*d_log << " max_items_avail = " << max_items_avail << std::endl); - LOG(*d_log << " noutput_items = " << noutput_items << std::endl); + LOG(std::ostringstream msg; msg << "max_items_avail = " << max_items_avail; + GR_LOG_INFO(d_debug_logger, msg.str());); + LOG(std::ostringstream msg; msg << "noutput_items = " << noutput_items; + GR_LOG_INFO(d_debug_logger, msg.str());); if (noutput_items == 0) { // we're blocked on input - LOG(*d_log << " BLKD_IN\n"); + LOG(GR_LOG_INFO(d_debug_logger, "BLKD_IN");); return BLKD_IN; } @@ -354,16 +354,18 @@ block_executor::state block_executor::run_one_iteration() noutput_items = min_available_space(d, m->output_multiple(), m->min_noutput_items()); if (ENABLE_LOGGING) { - *d_log << " regular "; - *d_log << m->relative_rate_i() << ":" << m->relative_rate_d() << std::endl; - *d_log << " max_items_avail = " << max_items_avail << std::endl; - *d_log << " noutput_items = " << noutput_items << std::endl; + std::ostringstream msg; + msg << "regular "; + msg << m->relative_rate_i() << ":" << m->relative_rate_d(); + msg << " max_items_avail = " << max_items_avail; + msg << " noutput_items = " << noutput_items; + GR_LOG_INFO(d_debug_logger, msg.str()); } if (noutput_items == -1) // we're done goto were_done; if (noutput_items == 0) { // we're output blocked - LOG(*d_log << " BLKD_OUT\n"); + LOG(GR_LOG_INFO(d_debug_logger, "BLKD_OUT");); return BLKD_OUT; } @@ -428,12 +430,13 @@ block_executor::state block_executor::run_one_iteration() break; if (d_ninput_items_required[i] < 0) { - std::cerr << "\nsched: <block " << m->name() << " (" << m->unique_id() - << ")>" - << " thinks its ninput_items required is " - << d_ninput_items_required[i] << " and cannot be negative.\n" - << "Some parameterization is wrong. " - << "Too large a decimation value?\n\n"; + std::ostringstream msg; + msg << "sched: <block " << m->name() << " (" << m->unique_id() << ")>" + << " thinks its ninput_items required is " + << d_ninput_items_required[i] << " and cannot be negative." + << "Some parameterization is wrong. " + << "Too large a decimation value?"; + GR_LOG_ERROR(d_logger, msg.str()); goto were_done; } } @@ -447,7 +450,7 @@ block_executor::state block_executor::run_one_iteration() } // We're blocked on input - LOG(*d_log << " BLKD_IN\n"); + LOG(GR_LOG_INFO(d_debug_logger, "BLKD_IN");); if (d_input_done[i]) // If the upstream block is done, we're done goto were_done; @@ -455,14 +458,15 @@ block_executor::state block_executor::run_one_iteration() buffer_reader_sptr in_buf = d->input(i); if (d_ninput_items_required[i] > in_buf->max_possible_items_available()) { // Nope, never going to happen... - std::cerr - << "\nsched: <block " << m->name() << " (" << m->unique_id() << ")>" - << " is requesting more input data\n" - << " than we can provide.\n" - << " ninput_items_required = " << d_ninput_items_required[i] << "\n" + std::ostringstream msg; + msg << "sched: <block " << m->name() << " (" << m->unique_id() << ")>" + << " is requesting more input data" + << " than we can provide." + << " ninput_items_required = " << d_ninput_items_required[i] << " max_possible_items_available = " - << in_buf->max_possible_items_available() << "\n" - << " If this is a filter, consider reducing the number of taps.\n"; + << in_buf->max_possible_items_available() + << " If this is a filter, consider reducing the number of taps."; + GR_LOG_ERROR(d_logger, msg.str()); goto were_done; } @@ -504,8 +508,9 @@ block_executor::state block_executor::run_one_iteration() d->stop_perf_counters(noutput_items, n); #endif /* GR_PERFORMANCE_COUNTERS */ - LOG(*d_log << " general_work: noutput_items = " << noutput_items - << " result = " << n << std::endl); + LOG(std::ostringstream msg; + msg << "general_work: noutput_items = " << noutput_items << " result = " << n; + GR_LOG_INFO(d_debug_logger, msg.str());); // Adjust number of unaligned items left to process if (m->is_unaligned()) { @@ -564,7 +569,7 @@ block_executor::state block_executor::run_one_iteration() assert(0); were_done: - LOG(*d_log << " were_done\n"); + LOG(GR_LOG_INFO(d_debug_logger, "we're done");); d->set_done(true); return DONE; } diff --git a/gnuradio-runtime/lib/block_executor.h b/gnuradio-runtime/lib/block_executor.h index 3b7089419b..9e123b180a 100644 --- a/gnuradio-runtime/lib/block_executor.h +++ b/gnuradio-runtime/lib/block_executor.h @@ -12,6 +12,7 @@ #define INCLUDED_GR_RUNTIME_BLOCK_EXECUTOR_H #include <gnuradio/api.h> +#include <gnuradio/logger.h> #include <gnuradio/runtime_types.h> #include <gnuradio/tags.h> #include <fstream> @@ -27,7 +28,8 @@ class GR_RUNTIME_API block_executor { protected: block_sptr d_block; // The block we're trying to run - std::unique_ptr<std::ofstream> d_log; + gr::logger_ptr d_logger; + gr::logger_ptr d_debug_logger; // These are allocated here so we don't have to on each iteration diff --git a/gnuradio-runtime/lib/buffer.cc b/gnuradio-runtime/lib/buffer.cc index 46d704542b..58b291e649 100644 --- a/gnuradio-runtime/lib/buffer.cc +++ b/gnuradio-runtime/lib/buffer.cc @@ -76,6 +76,7 @@ buffer::buffer(int nitems, size_t sizeof_item, block_sptr link) d_done(false), d_last_min_items_read(0) { + gr::configure_default_loggers(d_logger, d_debug_logger, "buffer"); if (!allocate_buffer(nitems, sizeof_item)) throw std::bad_alloc(); @@ -113,21 +114,24 @@ bool buffer::allocate_buffer(int nitems, size_t sizeof_item) // This only happens if sizeof_item is not a power of two. if (nitems > 2 * orig_nitems && nitems * (int)sizeof_item > granularity) { - std::cerr << "gr::buffer::allocate_buffer: warning: tried to allocate\n" - << " " << orig_nitems << " items of size " << sizeof_item - << ". Due to alignment requirements\n" - << " " << nitems - << " were allocated. If this isn't OK, consider padding\n" - << " your structure to a power-of-two bytes.\n" - << " On this platform, our allocation granularity is " << granularity - << " bytes.\n"; + auto msg = + str(boost::format( + "allocate_buffer: tried to allocate" + " %d items of size %d. Due to alignment requirements" + " %d were allocated. If this isn't OK, consider padding" + " your structure to a power-of-two bytes." + " On this platform, our allocation granularity is %d bytes.") % + orig_nitems % sizeof_item % nitems % granularity); + GR_LOG_WARN(d_logger, msg.c_str()); } d_bufsize = nitems; d_vmcircbuf.reset(gr::vmcircbuf_sysconfig::make(d_bufsize * d_sizeof_item)); if (d_vmcircbuf == 0) { - std::cerr << "gr::buffer::allocate_buffer: failed to allocate buffer of size " - << d_bufsize * d_sizeof_item / 1024 << " KB\n"; + std::ostringstream msg; + msg << "gr::buffer::allocate_buffer: failed to allocate buffer of size " + << d_bufsize * d_sizeof_item / 1024 << " KB"; + GR_LOG_ERROR(d_logger, msg.str()); return false; } diff --git a/gnuradio-runtime/lib/controlport/thrift/rpcpmtconverters_thrift.cc b/gnuradio-runtime/lib/controlport/thrift/rpcpmtconverters_thrift.cc index 74eb12dcc3..2aae09e1d0 100644 --- a/gnuradio-runtime/lib/controlport/thrift/rpcpmtconverters_thrift.cc +++ b/gnuradio-runtime/lib/controlport/thrift/rpcpmtconverters_thrift.cc @@ -9,6 +9,7 @@ #include "thrift/gnuradio_types.h" #include <gnuradio/gr_complex.h> +#include <gnuradio/logger.h> #include <gnuradio/rpcpmtconverters_thrift.h> #include <boost/assign/ptr_map_inserter.hpp> #include <iostream> @@ -109,8 +110,12 @@ GNURadio::Knob rpcpmtconverter::from_pmt(const pmt::pmt_t& knob) result.value.__set_a_c32vector(z); return result; } else { - std::cerr << "Error: Don't know how to handle Knob Type (from): " << knob - << std::endl; + // FIXME: Don't get loggers every time we need to log something. + gr::logger_ptr logger, debug_logger; + gr::configure_default_loggers(logger, debug_logger, "rpcpmtconverter"); + std::ostringstream msg; + msg << "ERROR Don't know how to handle Knob Type (from): " << knob; + GR_LOG_ERROR(logger, msg.str()); assert(0); } return GNURadio::Knob(); @@ -250,7 +255,12 @@ rpcpmtconverter::to_pmt_reg<TO_PMT_F>::to_pmt_reg(To_PMT& instance, pmt::pmt_t rpcpmtconverter::to_pmt_f::operator()(const GNURadio::Knob& knob) { - std::cerr << "Error: Don't know how to handle Knob Type: " << knob.type << std::endl; + // FIXME: Don't get loggers every time we need to log something. + gr::logger_ptr logger, debug_logger; + gr::configure_default_loggers(logger, debug_logger, "rpcpmtconverter"); + std::ostringstream msg; + msg << "ERROR Don't know how to handle Knob Type (from): " << knob.type; + GR_LOG_ERROR(debug_logger, msg.str()); assert(0); return pmt::pmt_t(); } diff --git a/gnuradio-runtime/lib/controlport/thrift/rpcserver_thrift.cc b/gnuradio-runtime/lib/controlport/thrift/rpcserver_thrift.cc index 603f82dee1..c2613c5c80 100644 --- a/gnuradio-runtime/lib/controlport/thrift/rpcserver_thrift.cc +++ b/gnuradio-runtime/lib/controlport/thrift/rpcserver_thrift.cc @@ -25,12 +25,13 @@ using namespace rpcpmtconverter; rpcserver_thrift::rpcserver_thrift() { - // std::cerr << "rpcserver_thrift::ctor" << std::endl; + gr::configure_default_loggers(logger, debug_logger, "rpcserver_thrift"); + // std::cerr << "rpcserver_thrift::ctor" ; } rpcserver_thrift::~rpcserver_thrift() { - // std::cerr << "rpcserver_thrift::dtor" << std::endl; + // std::cerr << "rpcserver_thrift::dtor" ; } void rpcserver_thrift::registerConfigureCallback(const std::string& id, @@ -43,13 +44,15 @@ void rpcserver_thrift::registerConfigureCallback(const std::string& id, std::stringstream s; s << "rpcserver_thrift:: rpcserver_thrift ERROR registering set, already " "registered: " - << id << std::endl; + << id; throw std::runtime_error(s.str().c_str()); } } if (DEBUG) { - std::cerr << "rpcserver_thrift registering set: " << id << std::endl; + std::ostringstream msg; + msg << "registering set: " << id; + GR_LOG_INFO(d_debug_logger, msg.str()); } d_setcallbackmap.insert(ConfigureCallbackMap_t::value_type(id, callback)); } @@ -62,12 +65,15 @@ void rpcserver_thrift::unregisterConfigureCallback(const std::string& id) std::stringstream s; s << "rpcserver_thrift:: rpcserver_thrift ERROR unregistering set, not " "registered: " - << id << std::endl; + << id; throw std::runtime_error(s.str().c_str()); } - if (DEBUG) - std::cerr << "rpcserver_thrift unregistering set: " << id << std::endl; + if (DEBUG) { + std::ostringstream msg; + msg << "unregistering set: " << id; + GR_LOG_INFO(d_debug_logger, msg.str()); + } d_setcallbackmap.erase(iter); } @@ -82,13 +88,15 @@ void rpcserver_thrift::registerQueryCallback(const std::string& id, std::stringstream s; s << "rpcserver_thrift:: rpcserver_thrift ERROR registering get, already " "registered: " - << id << std::endl; + << id; throw std::runtime_error(s.str().c_str()); } } if (DEBUG) { - std::cerr << "rpcserver_thrift registering get: " << id << std::endl; + std::ostringstream msg; + msg << "registering get: " << id; + GR_LOG_INFO(d_debug_logger, msg.str()); } d_getcallbackmap.insert(QueryCallbackMap_t::value_type(id, callback)); } @@ -100,12 +108,14 @@ void rpcserver_thrift::unregisterQueryCallback(const std::string& id) if (iter == d_getcallbackmap.end()) { std::stringstream s; s << "rpcserver_thrift:: rpcserver_thrift ERROR unregistering get, registered: " - << id << std::endl; + << id; throw std::runtime_error(s.str().c_str()); } if (DEBUG) { - std::cerr << "rpcserver_thrift unregistering get: " << id << std::endl; + std::ostringstream msg; + msg << "unregistering get: " << id; + GR_LOG_INFO(d_debug_logger, msg.str()); } d_getcallbackmap.erase(iter); @@ -122,13 +132,15 @@ void rpcserver_thrift::registerHandlerCallback(const std::string& id, std::stringstream s; s << "rpcserver_thrift:: rpcserver_thrift ERROR registering handler, already " "registered: " - << id << std::endl; + << id; throw std::runtime_error(s.str().c_str()); } } if (DEBUG) { - std::cerr << "rpcserver_thrift registering handler: " << id << std::endl; + std::ostringstream msg; + msg << "registering handler: " << id; + GR_LOG_INFO(d_debug_logger, msg.str()); } d_handlercallbackmap.insert(HandlerCallbackMap_t::value_type(id, callback)); } @@ -141,12 +153,14 @@ void rpcserver_thrift::unregisterHandlerCallback(const std::string& id) std::stringstream s; s << "rpcserver_thrift:: rpcserver_thrift ERROR unregistering handler, " "registered: " - << id << std::endl; + << id; throw std::runtime_error(s.str().c_str()); } if (DEBUG) { - std::cerr << "rpcserver_thrift unregistering handler: " << id << std::endl; + std::ostringstream msg; + msg << "unregistering handler: " << id; + GR_LOG_INFO(d_debug_logger, msg.str()); } d_handlercallbackmap.erase(iter); @@ -258,6 +272,8 @@ void rpcserver_thrift::postMessage(const std::string& alias, void rpcserver_thrift::shutdown() { if (DEBUG) { - std::cerr << "Shutting down..." << std::endl; + std::ostringstream msg; + msg << "shutting down... " << id; + GR_LOG_INFO(d_debug_logger, msg.str()); } } diff --git a/gnuradio-runtime/lib/local_sighandler.cc b/gnuradio-runtime/lib/local_sighandler.cc index 2f2b72063b..a50dab79c2 100644 --- a/gnuradio-runtime/lib/local_sighandler.cc +++ b/gnuradio-runtime/lib/local_sighandler.cc @@ -31,8 +31,10 @@ local_sighandler::local_sighandler(int signum, void (*new_handler)(int)) sigemptyset(&new_action.sa_mask); new_action.sa_flags = 0; + gr::configure_default_loggers(d_logger, d_debug_logger, "local_sighandler"); if (sigaction(d_signum, &new_action, &d_old_action) < 0) { - perror("sigaction (install new)"); + GR_LOG_ERROR(d_logger, + boost::format("sigaction (install new): %s") % strerror(errno)) throw std::runtime_error("sigaction"); } #endif @@ -42,7 +44,8 @@ local_sighandler::~local_sighandler() noexcept(false) { #ifdef HAVE_SIGACTION if (sigaction(d_signum, &d_old_action, 0) < 0) { - perror("sigaction (restore old)"); + GR_LOG_ERROR(d_logger, + boost::format("sigaction (restore old): %s") % strerror(errno)) throw std::runtime_error("sigaction"); } #endif diff --git a/gnuradio-runtime/lib/local_sighandler.h b/gnuradio-runtime/lib/local_sighandler.h index 31ab0d16c2..05eb8eedbc 100644 --- a/gnuradio-runtime/lib/local_sighandler.h +++ b/gnuradio-runtime/lib/local_sighandler.h @@ -16,6 +16,7 @@ #endif #include <gnuradio/api.h> +#include <gnuradio/logger.h> #include <string> namespace gr { @@ -36,6 +37,8 @@ private: #endif public: + gr::logger_ptr d_logger; + gr::logger_ptr d_debug_logger; local_sighandler(int signum, void (*new_handler)(int)); ~local_sighandler() noexcept(false); diff --git a/gnuradio-runtime/lib/pagesize.cc b/gnuradio-runtime/lib/pagesize.cc index ef149de629..9568ae76da 100644 --- a/gnuradio-runtime/lib/pagesize.cc +++ b/gnuradio-runtime/lib/pagesize.cc @@ -12,6 +12,9 @@ #include "config.h" #endif +#include <gnuradio/logger.h> +#include <gnuradio/prefs.h> + #include "pagesize.h" #include <stdio.h> #include <unistd.h> @@ -25,6 +28,8 @@ extern "C" size_t getpagesize(void); int pagesize() { static int s_pagesize = -1; + gr::logger_ptr logger, debug_logger; + gr::configure_default_loggers(logger, debug_logger, "pagesize"); if (s_pagesize == -1) { #if defined(HAVE_GETPAGESIZE) @@ -32,11 +37,11 @@ int pagesize() #elif defined(HAVE_SYSCONF) s_pagesize = sysconf(_SC_PAGESIZE); if (s_pagesize == -1) { - perror("_SC_PAGESIZE"); + GR_LOG_ERROR(logger, boost::format("_SC_PAGESIZE: %s") strerror(errno)); s_pagesize = 4096; } #else - fprintf(stderr, "gr::pagesize: no info; setting pagesize = 4096\n"); + GR_LOG_ERROR(logger, "no info; setting pagesize = 4096"); s_pagesize = 4096; #endif } diff --git a/gnuradio-runtime/lib/realtime_impl.cc b/gnuradio-runtime/lib/realtime_impl.cc index 573e46e05b..24e9c0d034 100644 --- a/gnuradio-runtime/lib/realtime_impl.cc +++ b/gnuradio-runtime/lib/realtime_impl.cc @@ -12,6 +12,8 @@ #include <config.h> #endif +#include <gnuradio/logger.h> +#include <gnuradio/prefs.h> #include <gnuradio/realtime_impl.h> #ifdef HAVE_SCHED_H @@ -109,8 +111,12 @@ rt_status_t enable_realtime_scheduling(rt_sched_param p) if (result == EPERM) // N.B., return value, not errno return RT_NO_PRIVS; else { - fprintf(stderr, - "pthread_setschedparam: failed to set real time priority: %s\n", + gr::logger_ptr logger, debug_logger; + gr::configure_default_loggers(logger, debug_logger, "realtime_impl"); + GR_LOG_ERROR( + logger, + boost::format( + "pthread_setschedparam: failed to set real time priority: %s") % strerror(result)); return RT_OTHER_ERROR; } @@ -148,7 +154,11 @@ rt_status_t enable_realtime_scheduling(rt_sched_param p) if (errno == EPERM) return RT_NO_PRIVS; else { - perror("sched_setscheduler: failed to set real time priority"); + gr::logger_ptr logger, debug_logger; + gr::configure_default_loggers(logger, debug_logger, "realtime_impl"); + GR_LOG_ERROR( + logger, + boost::format("sched_setscheduler: failed to set real time priority.")); return RT_OTHER_ERROR; } } diff --git a/gnuradio-runtime/lib/test.cc b/gnuradio-runtime/lib/test.cc index f78fd4623c..9f2e3c58e0 100644 --- a/gnuradio-runtime/lib/test.cc +++ b/gnuradio-runtime/lib/test.cc @@ -92,13 +92,12 @@ int test::general_work(int noutput_items, for (unsigned i = 0; i < ninputs; i++) { char* in = (char*)input_items[i]; if (ninput_items[i] < (int)(noutput_items + history())) { - std::cerr << "ERROR: ninput_items[" << i << "] < noutput_items+history()" - << std::endl; - std::cerr << "ninput_items[" << i << "] = " << ninput_items[i] << std::endl; - std::cerr << "noutput_items+history() = " << noutput_items + history() - << std::endl; - std::cerr << "noutput_items = " << noutput_items << std::endl; - std::cerr << "history() = " << history() << std::endl; + std::ostringstream msg; + msg << "ninput_items[" << i << "] < noutput_items+history()" + << "ninput_items[" << i << "] = " << ninput_items[i] + << "noutput_items+history() = " << (noutput_items + history()) + << "noutput_items = " << noutput_items << "history() = " << history(); + GR_LOG_ERROR(d_logger, msg.str()); throw std::runtime_error("test"); } else { for (int j = 0; j < ninput_items[i]; j++) { diff --git a/gnuradio-runtime/lib/thread/thread_body_wrapper.cc b/gnuradio-runtime/lib/thread/thread_body_wrapper.cc index 53fac78d93..b82623475b 100644 --- a/gnuradio-runtime/lib/thread/thread_body_wrapper.cc +++ b/gnuradio-runtime/lib/thread/thread_body_wrapper.cc @@ -12,6 +12,7 @@ #include <config.h> #endif +#include <gnuradio/logger.h> #include <gnuradio/thread/thread_body_wrapper.h> #ifdef HAVE_SIGNAL_H @@ -63,8 +64,13 @@ void mask_signals() sigaddset(&new_set, SIGXFSZ); #endif r = pthread_sigmask(SIG_BLOCK, &new_set, 0); - if (r != 0) - perror("pthread_sigmask"); + if (r != 0) { + // FIXME use predefined loggers + gr::logger_ptr logger, debug_logger; + gr::configure_default_loggers( + logger, debug_logger, "thread_body_wrapper::mask_signals"); + GR_LOG_ERROR(logger, boost::format("pthread_sigmask: %s") % strerror(errno)); + } } #else diff --git a/gnuradio-runtime/lib/top_block_impl.cc b/gnuradio-runtime/lib/top_block_impl.cc index bfc2bf310f..393f8adbe5 100644 --- a/gnuradio-runtime/lib/top_block_impl.cc +++ b/gnuradio-runtime/lib/top_block_impl.cc @@ -15,6 +15,7 @@ #include "flat_flowgraph.h" #include "scheduler_tpb.h" #include "top_block_impl.h" +#include <gnuradio/logger.h> #include <gnuradio/prefs.h> #include <gnuradio/top_block.h> @@ -57,8 +58,12 @@ make_scheduler(flat_flowgraph_sptr ffg, int max_noutput_items, bool catch_except } } if (factory == 0) { - std::cerr << "warning: Invalid GR_SCHEDULER environment variable value \"" - << v << "\". Using \"" << scheduler_table[0].name << "\"\n"; + gr::logger_ptr logger, debug_logger; + gr::configure_default_loggers(logger, debug_logger, "top_block_impl"); + std::ostringstream msg; + msg << "Invalid GR_SCHEDULER environment variable value \"" << v + << "\". Using \"" << scheduler_table[0].name << "\""; + GR_LOG_WARN(logger, msg.str()); factory = scheduler_table[0].f; } } @@ -74,13 +79,16 @@ top_block_impl::top_block_impl(top_block* owner, bool catch_exceptions = true) d_retry_wait(false), d_catch_exceptions(catch_exceptions) { + gr::configure_default_loggers(d_logger, d_debug_logger, "top_block_impl"); } top_block_impl::~top_block_impl() { if (d_lock_count) { - std::cerr << "error: destroying locked block." << std::endl; + GR_LOG_ERROR(d_logger, "destroying locked block."); } + // NOTE: Investigate the sensibility of setting a raw pointer to zero at the end of + // destructor d_owner = 0; } diff --git a/gnuradio-runtime/lib/top_block_impl.h b/gnuradio-runtime/lib/top_block_impl.h index 9bfedfd87d..0dc66b2455 100644 --- a/gnuradio-runtime/lib/top_block_impl.h +++ b/gnuradio-runtime/lib/top_block_impl.h @@ -78,6 +78,8 @@ protected: private: void restart(); void wait_for_jobs(); + + gr::logger_ptr d_logger, d_debug_logger; }; } /* namespace gr */ diff --git a/gnuradio-runtime/lib/vmcircbuf.cc b/gnuradio-runtime/lib/vmcircbuf.cc index 4af5262671..9a80d18a57 100644 --- a/gnuradio-runtime/lib/vmcircbuf.cc +++ b/gnuradio-runtime/lib/vmcircbuf.cc @@ -51,15 +51,16 @@ vmcircbuf_factory* vmcircbuf_sysconfig::get_default_factory() std::vector<gr::vmcircbuf_factory*> all = all_factories(); + logger_ptr logger, debug_logger; + gr::configure_default_loggers(logger, debug_logger, "vmcircbuf_sysconfig"); + char name[1024]; if (gr::vmcircbuf_prefs::get(FACTORY_PREF_KEY, name, sizeof(name)) >= 0) { for (unsigned int i = 0; i < all.size(); i++) { if (strncmp(name, all[i]->name(), strlen(all[i]->name())) == 0) { s_default_factory = all[i]; - if (verbose) - fprintf(stderr, - "gr::vmcircbuf_sysconfig: using %s\n", - s_default_factory->name()); + GR_LOG_INFO(debug_logger, + boost::format("Using %s") % s_default_factory->name()); return s_default_factory; } } @@ -68,8 +69,7 @@ vmcircbuf_factory* vmcircbuf_sysconfig::get_default_factory() // either we don't have a default, or the default named is not in our // list of factories. Find the first factory that works. - if (verbose) - fprintf(stderr, "gr::vmcircbuf_sysconfig: finding a working factory...\n"); + GR_LOG_INFO(debug_logger, "finding a working factory..."); for (unsigned int i = 0; i < all.size(); i++) { if (test_factory(all[i], verbose)) { @@ -79,7 +79,7 @@ vmcircbuf_factory* vmcircbuf_sysconfig::get_default_factory() } // We're screwed! - fprintf(stderr, "gr::vmcircbuf_sysconfig: unable to find a working factory!\n"); + GR_LOG_ERROR(logger, "unable to find a working factory!"); throw std::runtime_error("gr::vmcircbuf_sysconfig"); } @@ -115,36 +115,34 @@ static void init_buffer(const vmcircbuf& c, int counter, int size) p[i] = counter + i; } -static bool -check_mapping(const vmcircbuf& c, int counter, int size, const char* msg, bool verbose) +static bool check_mapping( + const vmcircbuf& c, int counter, int size, const char* msg, logger_ptr debug_logger) { bool ok = true; - if (verbose) - fprintf(stderr, "... %s", msg); + GR_LOG_INFO(debug_logger, msg); unsigned int* p1 = (unsigned int*)c.pointer_to_first_copy(); unsigned int* p2 = (unsigned int*)c.pointer_to_second_copy(); - // fprintf(stderr, "p1 = %p, p2 = %p\n", p1, p2); - for (unsigned int i = 0; i < size / sizeof(int); i++) { if (p1[i] != counter + i) { ok = false; - if (verbose) - fprintf(stderr, " p1[%d] == %u, expected %u\n", i, p1[i], counter + i); + GR_LOG_INFO(debug_logger, + boost::format("p1[%d] == %u, expected %u") % i % p1[i] % + (counter + i)); break; } if (p2[i] != counter + i) { - if (verbose) - fprintf(stderr, " p2[%d] == %u, expected %u\n", i, p2[i], counter + i); + GR_LOG_ERROR(debug_logger, + boost::format("p1[%d] == %u, expected %u") % i % p2[i] % + (counter + i)); ok = false; break; } } - - if (ok && verbose) { - fprintf(stderr, " OK\n"); + if (ok) { + GR_LOG_INFO(debug_logger, "mapping OK"); } return ok; } @@ -170,17 +168,17 @@ test_a_bunch(vmcircbuf_factory* factory, int n, int size, int* start_ptr, bool v std::vector<std::unique_ptr<vmcircbuf>> c(n); int cum_size = 0; + logger_ptr logger, debug_logger; + gr::configure_default_loggers(logger, debug_logger, "gr::test_a_bunch"); + for (int i = 0; i < n; i++) { counter[i] = *start_ptr; *start_ptr += size; if ((c[i] = std::unique_ptr<vmcircbuf>(factory->make(size))) == 0) { - if (verbose) - fprintf( - stderr, - "Failed to allocate gr::vmcircbuf number %d of size %d (cum = %s)\n", - i + 1, - size, - memsize(cum_size)); + GR_LOG_INFO(debug_logger, + boost::format("Failed to allocate gr::vmcircbuf " + "number %d of size %d (cum = %s)") % + (i + 1) % size % memsize(cum_size)) return false; } init_buffer(*c[i], counter[i], size); @@ -190,38 +188,41 @@ test_a_bunch(vmcircbuf_factory* factory, int n, int size, int* start_ptr, bool v for (int i = 0; i < n; i++) { std::string msg = str(boost::format("test_a_bunch_%dx%s[%d]") % n % memsize(size) % i); - ok &= check_mapping(*c[i], counter[i], size, msg.c_str(), verbose); + ok = check_mapping(*c[i], counter[i], size, msg.c_str(), debug_logger) && ok; } return ok; } static bool standard_tests(vmcircbuf_factory* f, int verbose) { - if (verbose >= 1) - fprintf(stderr, "Testing %s...\n", f->name()); + logger_ptr logger, debug_logger; + gr::configure_default_loggers(logger, debug_logger, "standard_tests"); + + GR_LOG_INFO(debug_logger, boost::format("Testing %s...") % f->name()); bool v = verbose >= 2; int granularity = f->granularity(); int start = 0; bool ok = true; - ok &= test_a_bunch(f, 1, 1 * granularity, &start, v); // 1 x 4KB = 4KB + ok = test_a_bunch(f, 1, 1 * granularity, &start, v) && ok; // 1 x 4KB = 4KB if (ok) { - ok &= test_a_bunch(f, 64, 4 * granularity, &start, v); // 64 x 16KB = 1MB - ok &= test_a_bunch(f, 4, 4 * (1L << 20), &start, v); // 4 x 4MB = 16MB - // ok &= test_a_bunch(f, 256, 256 * (1L << 10), &start, v); // 256 x 256KB = - // 64MB + ok = test_a_bunch(f, 64, 4 * granularity, &start, v) && ok; // 64 x 16KB = 1MB + ok = test_a_bunch(f, 4, 4 * (1L << 20), &start, v) && ok; // 4 x 4MB = 16MB + // ok = test_a_bunch(f, 256, 256 * (1L << 10), &start, v) && ok; // 256 x 256KB + // = 64MB } - if (verbose >= 1) - fprintf(stderr, "....... %s: %s", f->name(), ok ? "OK\n" : "Doesn't work\n"); - + GR_LOG_INFO(debug_logger, + boost::format("%s: %s") % f->name() % (ok ? "OK" : "Doesn't work")) return ok; } bool vmcircbuf_sysconfig::test_factory(vmcircbuf_factory* f, int verbose) { + logger_ptr logger, debug_logger; + gr::configure_default_loggers(logger, debug_logger, "gr::vmcircbuf_sysconfig"); // Install local signal handlers for SIGSEGV and SIGBUS. // If something goes wrong, these signals may be invoked. @@ -238,22 +239,15 @@ bool vmcircbuf_sysconfig::test_factory(vmcircbuf_factory* f, int verbose) try { return standard_tests(f, verbose); } catch (gr::signal& sig) { - if (verbose) { - fprintf(stderr, "....... %s: %s", f->name(), "Doesn't work\n"); - fprintf(stderr, - "gr::vmcircbuf_factory::test_factory (%s): caught %s\n", - f->name(), - sig.name().c_str()); - return false; - } + GR_LOG_INFO(debug_logger, + boost::format("vmcircbuf_factory::test_factory (%s): caught %s") % + f->name() % sig.name().c_str()) + return false; } catch (...) { - if (verbose) { - fprintf(stderr, "....... %s: %s", f->name(), "Doesn't work\n"); - fprintf(stderr, - "gr::vmcircbuf_factory::test_factory (%s): some kind of uncaught " - "exception\n", - f->name()); - } + GR_LOG_WARN(debug_logger, + boost::format("vmcircbuf_factory::test_factory (%s) some " + "kind of uncaught exception.") % + f->name()) return false; } return false; // never gets here. shut compiler up. diff --git a/gnuradio-runtime/lib/vmcircbuf.h b/gnuradio-runtime/lib/vmcircbuf.h index 8bb18e87c2..192f9b32bd 100644 --- a/gnuradio-runtime/lib/vmcircbuf.h +++ b/gnuradio-runtime/lib/vmcircbuf.h @@ -12,6 +12,8 @@ #define GR_VMCIRCBUF_H #include <gnuradio/api.h> +#include <gnuradio/logger.h> +#include <gnuradio/prefs.h> #include <gnuradio/thread/thread.h> #include <vector> @@ -28,9 +30,14 @@ class GR_RUNTIME_API vmcircbuf protected: int d_size; char* d_base; + logger_ptr d_logger; + logger_ptr d_debug_logger; // CREATORS - vmcircbuf(int size) : d_size(size), d_base(0){}; + vmcircbuf(int size) : d_size(size), d_base(0) + { + gr::configure_default_loggers(d_logger, d_debug_logger, "gr::vmcircbuf"); + }; public: virtual ~vmcircbuf(); diff --git a/gnuradio-runtime/lib/vmcircbuf_createfilemapping.cc b/gnuradio-runtime/lib/vmcircbuf_createfilemapping.cc index e4863353bd..04860103c6 100644 --- a/gnuradio-runtime/lib/vmcircbuf_createfilemapping.cc +++ b/gnuradio-runtime/lib/vmcircbuf_createfilemapping.cc @@ -36,6 +36,9 @@ static void werror(char* where, DWORD last_error) { char buf[1024]; + logger_ptr logger, debug_logger; + gr::configure_default_loggers(logger, debug_logger, "werror"); + FormatMessage(FORMAT_MESSAGE_FROM_SYSTEM, NULL, last_error, @@ -43,7 +46,7 @@ static void werror(char* where, DWORD last_error) buf, sizeof(buf) / sizeof(TCHAR), // buffer size NULL); - fprintf(stderr, "%s: Error %d: %s", where, last_error, buf); + GR_LOG_ERROR(logger, boost::format("%s: Error %d: %s" % where % last_error % buf)); return; } #endif @@ -51,8 +54,12 @@ static void werror(char* where, DWORD last_error) vmcircbuf_createfilemapping::vmcircbuf_createfilemapping(int size) : gr::vmcircbuf(size) { + gr::configure_default_loggers( + d_logger, d_debug_logger, "vmcircbuf_createfilemapping"); #if !defined(HAVE_CREATEFILEMAPPING) - fprintf(stderr, "%s: createfilemapping is not available\n", __FUNCTION__); + std::stringstream error_msg; + error_msg << __FUNCTION__ << ": createfilemapping is not available"; + GR_LOG_ERROR(d_logger, error_msg.str()); throw std::runtime_error("gr::vmcircbuf_createfilemapping"); #else gr::thread::scoped_lock guard(s_vm_mutex); @@ -60,7 +67,9 @@ vmcircbuf_createfilemapping::vmcircbuf_createfilemapping(int size) : gr::vmcircb static int s_seg_counter = 0; if (size <= 0 || (size % gr::pagesize()) != 0) { - fprintf(stderr, "gr::vmcircbuf_createfilemapping: invalid size = %d\n", size); + std::stringstream error_msg; + error_msg << "invalid size = " << size; + GR_LOG_ERROR(d_logger, error_msg.str()); throw std::runtime_error("gr::vmcircbuf_createfilemapping"); } @@ -129,12 +138,11 @@ vmcircbuf_createfilemapping::vmcircbuf_createfilemapping(int size) : gr::vmcircb } #ifdef DEBUG - fprintf(stderr, - "gr::vmcircbuf_mmap_createfilemapping: contiguous? mmap %p %p %p %p\n", - (char*)d_first_copy, - (char*)d_second_copy, - size, - (char*)d_first_copy + size); + std::stringstream info_msg; + info_msg << "contiguous? mmap " << (char*)d_first_copy; + info_msg << (char*)d_second_copy << size; + info_msg << (char*)d_first_copy + size; + GR_LOG_INFO(d_debug_logger, info_msg.str()); #endif // Now remember the important stuff diff --git a/gnuradio-runtime/lib/vmcircbuf_mmap_shm_open.cc b/gnuradio-runtime/lib/vmcircbuf_mmap_shm_open.cc index 573dd0d1c8..becbe4b27b 100644 --- a/gnuradio-runtime/lib/vmcircbuf_mmap_shm_open.cc +++ b/gnuradio-runtime/lib/vmcircbuf_mmap_shm_open.cc @@ -34,7 +34,9 @@ namespace gr { vmcircbuf_mmap_shm_open::vmcircbuf_mmap_shm_open(int size) : gr::vmcircbuf(size) { #if !defined(HAVE_MMAP) || !defined(HAVE_SHM_OPEN) - fprintf(stderr, "gr::vmcircbuf_mmap_shm_open: mmap or shm_open is not available\n"); + std::stringstream error_msg; + error_msg << "mmap or shm_open is not available"; + GR_LOG_ERROR(d_logger, error_msg.str()); throw std::runtime_error("gr::vmcircbuf_mmap_shm_open"); #else gr::thread::scoped_lock guard(s_vm_mutex); @@ -42,7 +44,7 @@ vmcircbuf_mmap_shm_open::vmcircbuf_mmap_shm_open(int size) : gr::vmcircbuf(size) static int s_seg_counter = 0; if (size <= 0 || (size % gr::pagesize()) != 0) { - fprintf(stderr, "gr::vmcircbuf_mmap_shm_open: invalid size = %d\n", size); + GR_LOG_ERROR(d_logger, "invalid size =" + std::to_string(size)); throw std::runtime_error("gr::vmcircbuf_mmap_shm_open"); } @@ -79,9 +81,9 @@ vmcircbuf_mmap_shm_open::vmcircbuf_mmap_shm_open(int size) : gr::vmcircbuf(size) EEXIST) // Named segment already exists (shouldn't happen). Try again continue; - static std::string msg = str( - boost::format("gr::vmcircbuf_mmap_shm_open: shm_open [%s]") % seg_name); - perror(msg.c_str()); + static std::string msg = + str(boost::format("shm_open [%s] failed") % seg_name); + GR_LOG_ERROR(d_logger, msg.c_str()); throw std::runtime_error("gr::vmcircbuf_mmap_shm_open"); } break; @@ -91,7 +93,7 @@ vmcircbuf_mmap_shm_open::vmcircbuf_mmap_shm_open(int size) : gr::vmcircbuf(size) // Now set it's length to 2x what we really want and mmap it in. if (ftruncate(shm_fd, (off_t)2 * size) == -1) { close(shm_fd); // cleanup - perror("gr::vmcircbuf_mmap_shm_open: ftruncate (1)"); + GR_LOG_ERROR(d_logger, "ftruncate failed"); throw std::runtime_error("gr::vmcircbuf_mmap_shm_open"); } @@ -100,14 +102,14 @@ vmcircbuf_mmap_shm_open::vmcircbuf_mmap_shm_open(int size) : gr::vmcircbuf(size) if (first_copy == MAP_FAILED) { close(shm_fd); // cleanup - perror("gr::vmcircbuf_mmap_shm_open: mmap (1)"); + GR_LOG_ERROR(d_logger, "mmap (1) failed"); throw std::runtime_error("gr::vmcircbuf_mmap_shm_open"); } // unmap the 2nd half if (munmap((char*)first_copy + size, size) == -1) { close(shm_fd); // cleanup - perror("gr::vmcircbuf_mmap_shm_open: munmap (1)"); + GR_LOG_ERROR(d_logger, "munmap (1) failed"); throw std::runtime_error("gr::vmcircbuf_mmap_shm_open"); } @@ -122,7 +124,7 @@ vmcircbuf_mmap_shm_open::vmcircbuf_mmap_shm_open(int size) : gr::vmcircbuf(size) if (second_copy == MAP_FAILED) { close(shm_fd); // cleanup - perror("gr::vmcircbuf_mmap_shm_open: mmap (2)"); + GR_LOG_ERROR(d_logger, "mmap (2) failed"); throw std::runtime_error("gr::vmcircbuf_mmap_shm_open"); } @@ -139,7 +141,7 @@ vmcircbuf_mmap_shm_open::vmcircbuf_mmap_shm_open(int size) : gr::vmcircbuf(size) close(shm_fd); // fd no longer needed. The mapping is retained. if (shm_unlink(seg_name.c_str()) == -1) { // unlink the seg_name. - perror("gr::vmcircbuf_mmap_shm_open: shm_unlink"); + GR_LOG_ERROR(d_logger, "shm_unlink failed"); throw std::runtime_error("gr::vmcircbuf_mmap_shm_open"); } @@ -155,7 +157,7 @@ vmcircbuf_mmap_shm_open::~vmcircbuf_mmap_shm_open() gr::thread::scoped_lock guard(s_vm_mutex); if (munmap(d_base, 2 * d_size) == -1) { - perror("gr::vmcircbuf_mmap_shm_open: munmap (2)"); + GR_LOG_ERROR(d_logger, "munmap (2) failed"); } #endif } diff --git a/gnuradio-runtime/lib/vmcircbuf_mmap_tmpfile.cc b/gnuradio-runtime/lib/vmcircbuf_mmap_tmpfile.cc index 6f9d7e4104..3fc03f66c5 100644 --- a/gnuradio-runtime/lib/vmcircbuf_mmap_tmpfile.cc +++ b/gnuradio-runtime/lib/vmcircbuf_mmap_tmpfile.cc @@ -36,13 +36,15 @@ namespace gr { vmcircbuf_mmap_tmpfile::vmcircbuf_mmap_tmpfile(int size) : gr::vmcircbuf(size) { #if !defined(HAVE_MMAP) - fprintf(stderr, "gr::vmcircbuf_mmap_tmpfile: mmap or mkstemp is not available\n"); + GR_LOG_ERROR(d_logger, "mmap or mkstemp is not available"); throw std::runtime_error("gr::vmcircbuf_mmap_tmpfile"); #else gr::thread::scoped_lock guard(s_vm_mutex); if (size <= 0 || (size % gr::pagesize()) != 0) { - fprintf(stderr, "gr::vmcircbuf_mmap_tmpfile: invalid size = %d\n", size); + std::stringstream error_msg; + error_msg << "invalid size = " << size; + GR_LOG_ERROR(d_logger, error_msg.str()); throw std::runtime_error("gr::vmcircbuf_mmap_tmpfile"); } @@ -62,16 +64,15 @@ vmcircbuf_mmap_tmpfile::vmcircbuf_mmap_tmpfile(int size) : gr::vmcircbuf(size) if (errno == EEXIST) // File already exists (shouldn't happen). Try again continue; - static std::string msg = - str(boost::format("gr::vmcircbuf_mmap_tmpfile: open [%s]") % seg_name); - perror(msg.c_str()); + static std::string msg = str(boost::format("open [%s]") % seg_name); + GR_LOG_ERROR(d_logger, msg.c_str()); throw std::runtime_error("gr::vmcircbuf_mmap_tmpfile"); } break; } if (unlink(seg_name.c_str()) == -1) { - perror("gr::vmcircbuf_mmap_tmpfile: unlink"); + GR_LOG_ERROR(d_logger, "unlink"); throw std::runtime_error("gr::vmcircbuf_mmap_tmpfile"); } @@ -79,7 +80,7 @@ vmcircbuf_mmap_tmpfile::vmcircbuf_mmap_tmpfile(int size) : gr::vmcircbuf(size) // Now set it's length to 2x what we really want and mmap it in. if (ftruncate(seg_fd, (off_t)2 * size) == -1) { close(seg_fd); // cleanup - perror("gr::vmcircbuf_mmap_tmpfile: ftruncate (1)"); + GR_LOG_ERROR(d_logger, "ftruncate (1) failed"); throw std::runtime_error("gr::vmcircbuf_mmap_tmpfile"); } @@ -88,14 +89,14 @@ vmcircbuf_mmap_tmpfile::vmcircbuf_mmap_tmpfile(int size) : gr::vmcircbuf(size) if (first_copy == MAP_FAILED) { close(seg_fd); // cleanup - perror("gr::vmcircbuf_mmap_tmpfile: mmap (1)"); + GR_LOG_ERROR(d_logger, "mmap (1) failed"); throw std::runtime_error("gr::vmcircbuf_mmap_tmpfile"); } // unmap the 2nd half if (munmap((char*)first_copy + size, size) == -1) { close(seg_fd); // cleanup - perror("gr::vmcircbuf_mmap_tmpfile: munmap (1)"); + GR_LOG_ERROR(d_logger, "munmap (1) failed"); throw std::runtime_error("gr::vmcircbuf_mmap_tmpfile"); } @@ -111,7 +112,7 @@ vmcircbuf_mmap_tmpfile::vmcircbuf_mmap_tmpfile(int size) : gr::vmcircbuf(size) if (second_copy == MAP_FAILED) { munmap(first_copy, size); // cleanup close(seg_fd); - perror("gr::vmcircbuf_mmap_tmpfile: mmap(2)"); + GR_LOG_ERROR(d_logger, "mmap (2) failed"); throw std::runtime_error("gr::vmcircbuf_mmap_tmpfile"); } @@ -120,7 +121,7 @@ vmcircbuf_mmap_tmpfile::vmcircbuf_mmap_tmpfile(int size) : gr::vmcircbuf(size) munmap(first_copy, size); // cleanup munmap(second_copy, size); close(seg_fd); - perror("gr::vmcircbuf_mmap_tmpfile: non-contiguous second copy"); + GR_LOG_ERROR(d_logger, "non-contiguous second copy"); throw std::runtime_error("gr::vmcircbuf_mmap_tmpfile"); } @@ -129,7 +130,7 @@ vmcircbuf_mmap_tmpfile::vmcircbuf_mmap_tmpfile(int size) : gr::vmcircbuf(size) munmap(first_copy, size); // cleanup munmap(second_copy, size); close(seg_fd); - perror("gr::vmcircbuf_mmap_tmpfile: ftruncate (2)"); + GR_LOG_ERROR(d_logger, "ftruncate (2) failed"); throw std::runtime_error("gr::vmcircbuf_mmap_tmpfile"); } @@ -148,7 +149,7 @@ vmcircbuf_mmap_tmpfile::~vmcircbuf_mmap_tmpfile() gr::thread::scoped_lock guard(s_vm_mutex); if (munmap(d_base, 2 * d_size) == -1) { - perror("gr::vmcircbuf_mmap_tmpfile: munmap(2)"); + GR_LOG_ERROR(d_logger, "munmap (2) failed"); } #endif } diff --git a/gnuradio-runtime/lib/vmcircbuf_prefs.cc b/gnuradio-runtime/lib/vmcircbuf_prefs.cc index 96f37b44a7..ac77e69f57 100644 --- a/gnuradio-runtime/lib/vmcircbuf_prefs.cc +++ b/gnuradio-runtime/lib/vmcircbuf_prefs.cc @@ -56,8 +56,13 @@ int vmcircbuf_prefs::get(const char* key, char* value, int value_size) gr::thread::scoped_lock guard(s_vm_mutex); FILE* fp = fopen(pathname(key).c_str(), "r"); + + gr::logger_ptr logger, debug_logger; + gr::configure_default_loggers(logger, debug_logger, "vmcircbuf_prefs::get"); + if (fp == 0) { - perror(pathname(key).c_str()); + GR_LOG_ERROR(logger, + boost::format("%s: %s") % pathname(key).c_str() % strerror(errno)); return 0; } @@ -65,7 +70,9 @@ int vmcircbuf_prefs::get(const char* key, char* value, int value_size) value[ret] = '\0'; if (ret == 0 && !feof(fp)) { if (ferror(fp) != 0) { - perror(pathname(key).c_str()); + GR_LOG_ERROR(logger, + boost::format("%s: %s") % pathname(key).c_str() % + strerror(errno)); fclose(fp); return -1; } @@ -79,17 +86,22 @@ void vmcircbuf_prefs::set(const char* key, const char* value) gr::thread::scoped_lock guard(s_vm_mutex); ensure_dir_path(); + gr::logger_ptr logger, debug_logger; + gr::configure_default_loggers(logger, debug_logger, "vmcircbuf_prefs::set"); FILE* fp = fopen(pathname(key).c_str(), "w"); if (fp == 0) { - perror(pathname(key).c_str()); + GR_LOG_ERROR(logger, + boost::format("%s: %s") % pathname(key).c_str() % strerror(errno)); return; } size_t ret = fwrite(value, 1, strlen(value), fp); if (ret == 0) { if (ferror(fp) != 0) { - perror(pathname(key).c_str()); + GR_LOG_ERROR(logger, + boost::format("%s: %s") % pathname(key).c_str() % + strerror(errno)); fclose(fp); return; } diff --git a/gnuradio-runtime/lib/vmcircbuf_sysv_shm.cc b/gnuradio-runtime/lib/vmcircbuf_sysv_shm.cc index 17aec482de..cf98cd6cb7 100644 --- a/gnuradio-runtime/lib/vmcircbuf_sysv_shm.cc +++ b/gnuradio-runtime/lib/vmcircbuf_sysv_shm.cc @@ -35,7 +35,7 @@ namespace gr { vmcircbuf_sysv_shm::vmcircbuf_sysv_shm(int size) : gr::vmcircbuf(size) { #if !defined(HAVE_SYS_SHM_H) - fprintf(stderr, "gr::vmcircbuf_sysv_shm: sysv shared memory is not available\n"); + GR_LOG_ERROR(d_logger, "sysv shared memory is not available"); throw std::runtime_error("gr::vmcircbuf_sysv_shm"); #else @@ -44,7 +44,7 @@ vmcircbuf_sysv_shm::vmcircbuf_sysv_shm(int size) : gr::vmcircbuf(size) int pagesize = gr::pagesize(); if (size <= 0 || (size % pagesize) != 0) { - fprintf(stderr, "gr::vmcircbuf_sysv_shm: invalid size = %d\n", size); + GR_LOG_ERROR(d_logger, boost::format("invalid size = %d") % size); throw std::runtime_error("gr::vmcircbuf_sysv_shm"); } @@ -60,19 +60,19 @@ vmcircbuf_sysv_shm::vmcircbuf_sysv_shm(int size) : gr::vmcircbuf(size) // buffer. Ideally we'd map it no access, but I don't think that's possible with // SysV if ((shmid_guard = shmget(IPC_PRIVATE, pagesize, IPC_CREAT | 0400)) == -1) { - perror("gr::vmcircbuf_sysv_shm: shmget (0)"); + GR_LOG_ERROR(d_logger, boost::format("shmget (0): %s") % strerror(errno)); continue; } if ((shmid2 = shmget(IPC_PRIVATE, 2 * size + 2 * pagesize, IPC_CREAT | 0700)) == -1) { - perror("gr::vmcircbuf_sysv_shm: shmget (1)"); + GR_LOG_ERROR(d_logger, boost::format("shmget (1): %s") % strerror(errno)); shmctl(shmid_guard, IPC_RMID, 0); continue; } if ((shmid1 = shmget(IPC_PRIVATE, size, IPC_CREAT | 0700)) == -1) { - perror("gr::vmcircbuf_sysv_shm: shmget (2)"); + GR_LOG_ERROR(d_logger, boost::format("shmget (2): %s") % strerror(errno)); shmctl(shmid_guard, IPC_RMID, 0); shmctl(shmid2, IPC_RMID, 0); continue; @@ -80,7 +80,7 @@ vmcircbuf_sysv_shm::vmcircbuf_sysv_shm(int size) : gr::vmcircbuf(size) void* first_copy = shmat(shmid2, 0, 0); if (first_copy == (void*)-1) { - perror("gr::vmcircbuf_sysv_shm: shmat (1)"); + GR_LOG_ERROR(d_logger, boost::format("shmat (1): %s") % strerror(errno)); shmctl(shmid_guard, IPC_RMID, 0); shmctl(shmid2, IPC_RMID, 0); shmctl(shmid1, IPC_RMID, 0); @@ -100,7 +100,7 @@ vmcircbuf_sysv_shm::vmcircbuf_sysv_shm(int size) : gr::vmcircbuf(size) // first read-only guard page if (shmat(shmid_guard, first_copy, SHM_RDONLY) == (void*)-1) { - perror("gr::vmcircbuf_sysv_shm: shmat (2)"); + GR_LOG_ERROR(d_logger, boost::format("shmat (2): %s") % strerror(errno)); shmctl(shmid_guard, IPC_RMID, 0); shmctl(shmid1, IPC_RMID, 0); continue; @@ -108,7 +108,7 @@ vmcircbuf_sysv_shm::vmcircbuf_sysv_shm(int size) : gr::vmcircbuf(size) // first copy if (shmat(shmid1, (char*)first_copy + pagesize, 0) == (void*)-1) { - perror("gr::vmcircbuf_sysv_shm: shmat (3)"); + GR_LOG_ERROR(d_logger, boost::format("shmat (3): %s") % strerror(errno)); shmctl(shmid_guard, IPC_RMID, 0); shmctl(shmid1, IPC_RMID, 0); shmdt(first_copy); @@ -117,7 +117,7 @@ vmcircbuf_sysv_shm::vmcircbuf_sysv_shm(int size) : gr::vmcircbuf(size) // second copy if (shmat(shmid1, (char*)first_copy + pagesize + size, 0) == (void*)-1) { - perror("gr::vmcircbuf_sysv_shm: shmat (4)"); + GR_LOG_ERROR(d_logger, boost::format("shmat (4): %s") % strerror(errno)); shmctl(shmid_guard, IPC_RMID, 0); shmctl(shmid1, IPC_RMID, 0); shmdt((char*)first_copy + pagesize); @@ -127,7 +127,7 @@ vmcircbuf_sysv_shm::vmcircbuf_sysv_shm(int size) : gr::vmcircbuf(size) // second read-only guard page if (shmat(shmid_guard, (char*)first_copy + pagesize + 2 * size, SHM_RDONLY) == (void*)-1) { - perror("gr::vmcircbuf_sysv_shm: shmat (5)"); + GR_LOG_ERROR(d_logger, boost::format("shmat (5): %s") % strerror(errno)); shmctl(shmid_guard, IPC_RMID, 0); shmctl(shmid1, IPC_RMID, 0); shmdt(first_copy); @@ -157,7 +157,7 @@ vmcircbuf_sysv_shm::~vmcircbuf_sysv_shm() if (shmdt(d_base - gr::pagesize()) == -1 || shmdt(d_base) == -1 || shmdt(d_base + d_size) == -1 || shmdt(d_base + 2 * d_size) == -1) { - perror("gr::vmcircbuf_sysv_shm: shmdt (2)"); + GR_LOG_ERROR(d_logger, boost::format("shmdt (2): %s") % strerror(errno)); } #endif } |