diff options
| -rw-r--r-- | src/DabMod.cpp | 7 | ||||
| -rw-r--r-- | src/InputZeroMQReader.cpp | 4 | ||||
| -rw-r--r-- | src/Log.cpp | 48 | ||||
| -rw-r--r-- | src/Log.h | 41 | ||||
| -rw-r--r-- | src/OutputUHD.cpp | 7 | 
5 files changed, 93 insertions, 14 deletions
| diff --git a/src/DabMod.cpp b/src/DabMod.cpp index a60bdd6..e0e7f8e 100644 --- a/src/DabMod.cpp +++ b/src/DabMod.cpp @@ -394,6 +394,12 @@ int launch_modulator(int argc, char* argv[])              etiLog.register_backend(log_file);          } +        auto trace_filename = pt.get<std::string>("log.trace", ""); +        if (not trace_filename.empty()) { +            LogTracer* tracer = new LogTracer(trace_filename); +            etiLog.register_backend(tracer); +        } +          // modulator parameters:          gainMode = (GainMode)pt.get("modulator.gainmode", 0); @@ -776,6 +782,7 @@ int launch_modulator(int argc, char* argv[])          m.inputReader->PrintInfo();          run_modulator_state_t st = run_modulator(m); +        etiLog.log(trace, "DABMOD,run_modulator() = %d", st);          switch (st) {              case run_modulator_state_t::failure: diff --git a/src/InputZeroMQReader.cpp b/src/InputZeroMQReader.cpp index 69e1ffd..96e3223 100644 --- a/src/InputZeroMQReader.cpp +++ b/src/InputZeroMQReader.cpp @@ -96,11 +96,14 @@ int InputZeroMQReader::GetNextFrame(void* buffer)       */      if (in_messages_.size() < 4) {          const size_t prebuffering = 10; +        etiLog.log(trace, "ZMQ,wait1");          in_messages_.wait_and_pop(incoming, prebuffering);      }      else { +        etiLog.log(trace, "ZMQ,wait2");          in_messages_.wait_and_pop(incoming);      } +    etiLog.log(trace, "ZMQ,pop");      if (not worker_.is_running()) {          throw zmq_input_overflow(); @@ -183,6 +186,7 @@ void InputZeroMQWorker::RecvProcess(struct InputZeroMQThreadData* workerdata)                          offset += framesize;                          queue_size = workerdata->in_messages->push(buf); +                        etiLog.log(trace, "ZMQ,push %zu", queue_size);                      }                  }              } diff --git a/src/Log.cpp b/src/Log.cpp index 6bbc7a9..7d6d6f5 100644 --- a/src/Log.cpp +++ b/src/Log.cpp @@ -24,9 +24,12 @@  #include <list>  #include <stdarg.h> +#include <chrono>  #include "Log.h" +using namespace std; +  Logger etiLog; @@ -72,15 +75,56 @@ void Logger::logstr(log_level_t level, std::string message)          backend->log(level, message);      } -    { +    if (level != log_level_t::trace) {          std::lock_guard<std::mutex> guard(m_cerr_mutex);          std::cerr << levels_as_str[level] << " " << message << std::endl;      }  } -  LogLine Logger::level(log_level_t level)  {      return LogLine(this, level);  } +void LogToFile::log(log_level_t level, std::string message) +{ +    if (level != log_level_t::trace) { +        const char* log_level_text[] = { +            "DEBUG", "INFO", "WARN", "ERROR", "ALERT", "EMERG"}; + +        // fprintf is thread-safe +        fprintf(log_file, SYSLOG_IDENT ": %s: %s\n", +                log_level_text[(size_t)level], message.c_str()); +        fflush(log_file); +    } +} + +LogTracer::LogTracer(const string& trace_filename) +{ +    name = "TRACE"; +    etiLog.level(info) << "Setting up TRACE to " << trace_filename; + +    m_trace_file = fopen(trace_filename.c_str(), "a"); +    if (m_trace_file == NULL) { +        fprintf(stderr, "Cannot open trace file !"); +        throw std::runtime_error("Cannot open trace file !"); +    } + +    auto now = chrono::steady_clock::now().time_since_epoch(); +    m_trace_micros_startup = +        chrono::duration_cast<chrono::microseconds>(now).count(); + +    fprintf(m_trace_file, "0,TRACER,startup at %ld\n", m_trace_micros_startup); +} + +void LogTracer::log(log_level_t level, std::string message) +{ +    if (level == log_level_t::trace) { +        const auto now = chrono::steady_clock::now().time_since_epoch(); +        const auto micros = chrono::duration_cast<chrono::microseconds>(now).count(); + +        fprintf(m_trace_file, "%ld,%s\n", +                micros - m_trace_micros_startup, +                message.c_str()); +    } +} @@ -44,10 +44,10 @@  #define SYSLOG_IDENT "ODR-DabMod"  #define SYSLOG_FACILITY LOG_LOCAL0 -enum log_level_t {debug = 0, info, warn, error, alert, emerg}; +enum log_level_t {debug = 0, info, warn, error, alert, emerg, trace};  static const std::string levels_as_str[] = -    { "     ", "     ", "WARN ", "ERROR", "ALERT", "EMERG"} ; +    { "     ", "     ", "WARN ", "ERROR", "ALERT", "EMERG", "TRACE"} ;  /** Abstract class all backends must inherit from */  class LogBackend { @@ -72,6 +72,7 @@ class LogToSyslog : public LogBackend {              int syslog_level = LOG_EMERG;              switch (level) { +                case trace: break; // Do not handle TRACE in syslog                  case debug: syslog_level = LOG_DEBUG; break;                  case info:  syslog_level = LOG_INFO; break;                  /* we don't have the notice level */ @@ -89,6 +90,9 @@ class LogToSyslog : public LogBackend {      private:          std::string name; + +        LogToSyslog(const LogToSyslog& other) = delete; +        const LogToSyslog& operator=(const LogToSyslog& other) = delete;  };  class LogToFile : public LogBackend { @@ -109,22 +113,37 @@ class LogToFile : public LogBackend {              }          } -        void log(log_level_t level, std::string message) { +        void log(log_level_t level, std::string message); + +        std::string get_name() { return name; } -            const char* log_level_text[] = -                {"DEBUG", "INFO", "WARN", "ERROR", "ALERT", "EMERG"}; +    private: +        std::string name; +        FILE* log_file; -            // fprintf is thread-safe -            fprintf(log_file, SYSLOG_IDENT ": %s: %s\n", -                    log_level_text[(size_t)level], message.c_str()); -            fflush(log_file); +        LogToFile(const LogToFile& other) = delete; +        const LogToFile& operator=(const LogToFile& other) = delete; +}; + +class LogTracer : public LogBackend { +    public: +        LogTracer(const std::string& filename); + +        ~LogTracer() { +            if (m_trace_file != NULL) { +                fclose(m_trace_file); +            }          } +        void log(log_level_t level, std::string message);          std::string get_name() { return name; } -      private:          std::string name; -        FILE* log_file; +        uint64_t m_trace_micros_startup; +        FILE* m_trace_file; + +        LogTracer(const LogTracer& other) = delete; +        const LogTracer& operator=(const LogTracer& other) = delete;  };  class LogLine; diff --git a/src/OutputUHD.cpp b/src/OutputUHD.cpp index 4d51dc4..a49b659 100644 --- a/src/OutputUHD.cpp +++ b/src/OutputUHD.cpp @@ -407,7 +407,8 @@ int OutputUHD::process(Buffer* dataIn, Buffer* dataOut)                      usleep(10000); // 10ms                  } -                uwd.frames.push(frame); +                size_t num_frames = uwd.frames.push(frame); +                etiLog.log(trace, "UHD,push %zu", num_frames);                  break;              }          } @@ -619,7 +620,9 @@ void UHDWorker::process()          md.time_spec      = uhd::time_spec_t(0.0);          struct UHDWorkerFrameData frame; +        etiLog.log(trace, "UHD,wait");          uwd->frames.wait_and_pop(frame); +        etiLog.log(trace, "UHD,pop");          handle_frame(&frame);      } @@ -708,6 +711,7 @@ void UHDWorker::handle_frame(const struct UHDWorkerFrameData *frame)          md.has_time_spec = true;          md.time_spec = uhd::time_spec_t(tx_second, pps_offset); +        etiLog.log(trace, "UHD,tist %f", md.time_spec.get_real_secs());          // md is defined, let's do some checks          if (md.time_spec.get_real_secs() + tx_timeout < usrp_time) { @@ -801,6 +805,7 @@ void UHDWorker::tx_frame(const struct UHDWorkerFrameData *frame, bool ts_update)          size_t num_tx_samps = myTxStream->send(                  &in_data[num_acc_samps],                  samps_to_send, md_tx, tx_timeout); +        etiLog.log(trace, "UHD,sent %zu of %zu", num_tx_samps, samps_to_send);  #endif          num_acc_samps += num_tx_samps; | 
