aboutsummaryrefslogtreecommitdiffstats
diff options
context:
space:
mode:
-rw-r--r--src/DabMod.cpp7
-rw-r--r--src/InputZeroMQReader.cpp4
-rw-r--r--src/Log.cpp48
-rw-r--r--src/Log.h41
-rw-r--r--src/OutputUHD.cpp7
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());
+ }
+}
diff --git a/src/Log.h b/src/Log.h
index f3b4409..cbc3569 100644
--- a/src/Log.h
+++ b/src/Log.h
@@ -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;