diff --git a/lib/include/srslte/common/log.h b/lib/include/srslte/common/log.h index 35147095b..22a74c611 100644 --- a/lib/include/srslte/common/log.h +++ b/lib/include/srslte/common/log.h @@ -65,9 +65,7 @@ public: tti = 0; level = LOG_LEVEL_NONE; hex_limit = 0; - show_layer_en = true; add_string_en = false; - level_text_short = true; } log(std::string service_name_) { @@ -75,9 +73,7 @@ public: tti = 0; level = LOG_LEVEL_NONE; hex_limit = 0; - show_layer_en = true; add_string_en = false; - level_text_short = true; } virtual ~log() {}; @@ -131,12 +127,6 @@ public: int get_hex_limit() { return hex_limit; } - void set_log_level_short(bool enable) { - level_text_short = enable; - } - void show_layer(bool enable) { - show_layer_en = enable; - } // Pure virtual methods for logging virtual void console(const char * message, ...) __attribute__ ((format (printf, 2, 3))) = 0; @@ -162,8 +152,6 @@ protected: int hex_limit; std::string service_name; - bool show_layer_en; - bool level_text_short; bool add_string_en; std::string add_string_val; }; diff --git a/lib/include/srslte/common/log_filter.h b/lib/include/srslte/common/log_filter.h index 58a7dba6a..086e7adc8 100644 --- a/lib/include/srslte/common/log_filter.h +++ b/lib/include/srslte/common/log_filter.h @@ -82,15 +82,16 @@ protected: logger *logger_h; bool do_tti; + static const int char_buff_size = 512; + time_itf *time_src; time_format_t time_format; logger_stdout def_logger_stdout; - void all_log(srslte::LOG_LEVEL_ENUM level, uint32_t tti, const char *msg); - void all_log(srslte::LOG_LEVEL_ENUM level, uint32_t tti, const char *msg, const uint8_t *hex, int size); - void all_log_line(srslte::LOG_LEVEL_ENUM level, uint32_t tti, std::string file, int line, char *msg); - std::string now_time(); + void all_log(srslte::LOG_LEVEL_ENUM level, uint32_t tti, const char* msg, const uint8_t* hex = nullptr, int size = 0); + void now_time(char* buffer, const uint32_t buffer_len); + void get_tti_str(const uint32_t tti_, char* buffer, const uint32_t buffer_len); std::string hex_string(const uint8_t *hex, int size); }; diff --git a/lib/include/srslte/common/logger.h b/lib/include/srslte/common/logger.h index bafd05f17..1f7978d26 100644 --- a/lib/include/srslte/common/logger.h +++ b/lib/include/srslte/common/logger.h @@ -27,6 +27,8 @@ #ifndef SRSLTE_LOGGER_H #define SRSLTE_LOGGER_H +#include "buffer_pool.h" +#include #include #include @@ -35,9 +37,55 @@ namespace srslte { class logger { public: - virtual void log(std::string *msg) = 0; + logger() : pool(16 * 1024) {} + + class log_str + { + public: + log_str(const char* msg_) { strncpy(msg, msg_, size); } + log_str() { reset(); } + void reset() { msg[0] = '\0'; } + const static int size = 512; + char msg[size]; + }; + + typedef buffer_pool log_str_pool_t; + + class log_str_deleter + { + public: + explicit log_str_deleter(log_str_pool_t* pool_ = nullptr) : pool(pool_) {} + void operator()(log_str* buf) + { + if (buf) { + if (pool) { + buf->reset(); + pool->deallocate(buf); + } else + delete buf; + } + } + + private: + log_str_pool_t* pool; + }; + typedef std::unique_ptr unique_log_str_t; + + void log_char(const char* msg) { log(std::move(unique_log_str_t(new log_str(msg), log_str_deleter()))); } + + virtual void log(unique_log_str_t msg) = 0; + + log_str_pool_t& get_pool() { return pool; } + +private: + log_str_pool_t pool; }; +inline logger::unique_log_str_t allocate_unique_log_str(logger::log_str_pool_t& pool) +{ + return logger::unique_log_str_t(pool.allocate(), logger::log_str_deleter(&pool)); +} + } // namespace srslte #endif // SRSLTE_LOGGER_H diff --git a/lib/include/srslte/common/logger_file.h b/lib/include/srslte/common/logger_file.h index 17f08ef5e..543fa4a1e 100644 --- a/lib/include/srslte/common/logger_file.h +++ b/lib/include/srslte/common/logger_file.h @@ -48,8 +48,7 @@ public: ~logger_file(); void init(std::string file, int max_length = -1); // Implementation of log_out - void log(str_ptr msg); - void log(const char *msg); + void log(unique_log_str_t msg); private: void run_thread(); @@ -63,7 +62,8 @@ private: std::string filename; pthread_cond_t not_empty; pthread_mutex_t mutex; - std::deque buffer; + + std::deque buffer; }; } // namespace srslte diff --git a/lib/include/srslte/common/logger_stdout.h b/lib/include/srslte/common/logger_stdout.h index 7cdc9323b..ed99cf1d5 100644 --- a/lib/include/srslte/common/logger_stdout.h +++ b/lib/include/srslte/common/logger_stdout.h @@ -36,12 +36,7 @@ namespace srslte { class logger_stdout : public logger { public: - void log(std::string *msg) { - if (msg) { - fprintf(stdout, "%s", msg->c_str()); - delete msg; - } - } + void log(unique_log_str_t log_str) { fprintf(stdout, "%s", log_str->msg); } }; } // namespace srslte diff --git a/lib/src/common/log_filter.cc b/lib/src/common/log_filter.cc index 16788c205..c8e98639d 100644 --- a/lib/src/common/log_filter.cc +++ b/lib/src/common/log_filter.cc @@ -65,173 +65,128 @@ void log_filter::init(std::string layer, logger *logger_, bool tti) do_tti = tti; } -void log_filter::all_log(srslte::LOG_LEVEL_ENUM level, - uint32_t tti, - const char *msg) +void log_filter::all_log(srslte::LOG_LEVEL_ENUM level, uint32_t tti, const char* msg, const uint8_t* hex, int size) { - if(logger_h) { - std::stringstream ss; + char buffer_tti[16]; + char buffer_time[64]; - ss << now_time() << " "; - if (show_layer_en) { - ss << "[" <get_pool()); - str_ptr s_ptr(new std::string(ss.str())); - logger_h->log(s_ptr); - } -} + if (log_str) { + now_time(buffer_time, sizeof(buffer_time)); + if (do_tti) { + get_tti_str(tti, buffer_tti, sizeof(buffer_tti)); + } -void log_filter::all_log(srslte::LOG_LEVEL_ENUM level, - uint32_t tti, - const char *msg, - const uint8_t *hex, - int size) -{ - if(logger_h) { - std::stringstream ss; + snprintf(log_str->msg, + log_str->size, + "%s [%s] %s %s%s%s%s%s", + buffer_time, + get_service_name().c_str(), + log_level_text_short[level], + do_tti ? buffer_tti : "", + add_string_en ? add_string_val.c_str() : "", + msg, + msg[strlen(msg) - 1] != '\n' ? "\n" : "", + (hex_limit > 0 && hex && size > 0) ? hex_string(hex, size).c_str() : ""); - ss << now_time() << " "; - if (show_layer_en) { - ss << "[" <log(std::move(log_str)); } else { - ss << log_level_text[level] << " "; + logger_h->log_char("Error in Log: Not enough buffers in pool\n"); } - - if(do_tti) { - ss << "[" << std::setfill('0') << std::setw(5) << tti << "] "; - } - - if (add_string_en) { - ss << add_string_val << " "; - } - ss << msg; - - if (msg[strlen(msg)-1] != '\n') { - ss << std::endl; - } - - if (hex_limit > 0 && hex && size > 0) { - ss << hex_string(hex, size); - } - str_ptr s_ptr(new std::string(ss.str())); - logger_h->log(s_ptr); } } void log_filter::console(const char * message, ...) { - char *args_msg = NULL; + char args_msg[char_buff_size]; va_list args; va_start(args, message); - if(vasprintf(&args_msg, message, args) > 0) + if (vsnprintf(args_msg, char_buff_size, message, args) > 0) printf("%s",args_msg); // Print directly to stdout fflush(stdout); va_end(args); - free(args_msg); } void log_filter::error(const char * message, ...) { if (level >= LOG_LEVEL_ERROR) { - char *args_msg = NULL; + char args_msg[char_buff_size]; va_list args; va_start(args, message); - if(vasprintf(&args_msg, message, args) > 0) + if (vsnprintf(args_msg, char_buff_size, message, args) > 0) all_log(LOG_LEVEL_ERROR, tti, args_msg); va_end(args); - free(args_msg); } } void log_filter::warning(const char * message, ...) { if (level >= LOG_LEVEL_WARNING) { - char *args_msg = NULL; + char args_msg[char_buff_size]; va_list args; va_start(args, message); - if(vasprintf(&args_msg, message, args) > 0) + if (vsnprintf(args_msg, char_buff_size, message, args) > 0) all_log(LOG_LEVEL_WARNING, tti, args_msg); va_end(args); - free(args_msg); } } void log_filter::info(const char * message, ...) { if (level >= LOG_LEVEL_INFO) { - char *args_msg = NULL; + char args_msg[char_buff_size]; va_list args; va_start(args, message); - if(vasprintf(&args_msg, message, args) > 0) + if (vsnprintf(args_msg, char_buff_size, message, args) > 0) all_log(LOG_LEVEL_INFO, tti, args_msg); va_end(args); - free(args_msg); } } void log_filter::debug(const char * message, ...) { if (level >= LOG_LEVEL_DEBUG) { - char *args_msg = NULL; + char args_msg[char_buff_size]; va_list args; va_start(args, message); - if(vasprintf(&args_msg, message, args) > 0) + if (vsnprintf(args_msg, char_buff_size, message, args) > 0) all_log(LOG_LEVEL_DEBUG, tti, args_msg); va_end(args); - free(args_msg); } } void log_filter::error_hex(const uint8_t *hex, int size, const char * message, ...) { if (level >= LOG_LEVEL_ERROR) { - char *args_msg = NULL; + char args_msg[char_buff_size]; va_list args; va_start(args, message); - if(vasprintf(&args_msg, message, args) > 0) + if (vsnprintf(args_msg, char_buff_size, message, args) > 0) all_log(LOG_LEVEL_ERROR, tti, args_msg, hex, size); va_end(args); - free(args_msg); } } void log_filter::warning_hex(const uint8_t *hex, int size, const char * message, ...) { if (level >= LOG_LEVEL_WARNING) { - char *args_msg = NULL; + char args_msg[char_buff_size]; va_list args; va_start(args, message); - if(vasprintf(&args_msg, message, args) > 0) + if (vsnprintf(args_msg, char_buff_size, message, args) > 0) all_log(LOG_LEVEL_WARNING, tti, args_msg, hex, size); va_end(args); - free(args_msg); } } void log_filter::info_hex(const uint8_t *hex, int size, const char * message, ...) { if (level >= LOG_LEVEL_INFO) { - char *args_msg = NULL; + char args_msg[char_buff_size]; va_list args; va_start(args, message); - if(vasprintf(&args_msg, message, args) > 0) + if (vsnprintf(args_msg, char_buff_size, message, args) > 0) all_log(LOG_LEVEL_INFO, tti, args_msg, hex, size); va_end(args); - free(args_msg); } } void log_filter::debug_hex(const uint8_t *hex, int size, const char * message, ...) { if (level >= LOG_LEVEL_DEBUG) { - char *args_msg = NULL; + char args_msg[char_buff_size]; va_list args; va_start(args, message); - if(vasprintf(&args_msg, message, args) > 0) + if (vsnprintf(args_msg, char_buff_size, message, args) > 0) all_log(LOG_LEVEL_DEBUG, tti, args_msg, hex, size); va_end(args); - free(args_msg); } } @@ -239,42 +194,48 @@ void log_filter::set_time_src(time_itf *source, time_format_t format) { this->time_src = source; this->time_format = format; } +void log_filter::get_tti_str(const uint32_t tti_, char* buffer, const uint32_t buffer_len) +{ + snprintf(buffer, buffer_len, "[%5d] ", tti_); +} -std::string log_filter::now_time() +void log_filter::now_time(char* buffer, const uint32_t buffer_len) { struct timeval rawtime; struct tm * timeinfo; - char buffer[64]; char us[16]; srslte_timestamp_t now; uint64_t usec_epoch; + if (buffer_len < 16) { + fprintf(stderr, "Error buffer provided for time too small\n"); + return; + } + if (!time_src) { gettimeofday(&rawtime, NULL); timeinfo = localtime(&rawtime.tv_sec); if (time_format == TIME) { - strftime(buffer, 64, "%H:%M:%S", timeinfo); - strcat(buffer, "."); + strftime(buffer, buffer_len, "%H:%M:%S.", timeinfo); snprintf(us, 16, "%06ld", rawtime.tv_usec); - strcat(buffer, us); + uint32_t dest_len = strlen(buffer); + strncat(buffer, us, buffer_len - dest_len - 1); } else { usec_epoch = rawtime.tv_sec * 1000000 + rawtime.tv_usec; - snprintf(buffer, 64, "%ld", usec_epoch); + snprintf(buffer, buffer_len, "%ld", usec_epoch); } } else { now = time_src->get_time(); if (time_format == TIME) { - snprintf(buffer, 64, "%ld:%06u", now.full_secs, (uint32_t) (now.frac_secs * 1e6)); + snprintf(buffer, buffer_len, "%ld:%06u", now.full_secs, (uint32_t)(now.frac_secs * 1e6)); } else { usec_epoch = now.full_secs * 1000000 + (uint32_t) (now.frac_secs * 1e6); - snprintf(buffer, 64, "%ld", usec_epoch); + snprintf(buffer, buffer_len, "%ld", usec_epoch); } } - - return std::string(buffer); } std::string log_filter::hex_string(const uint8_t *hex, int size) diff --git a/lib/src/common/logger_file.cc b/lib/src/common/logger_file.cc index 0e89ff360..7f0f63093 100644 --- a/lib/src/common/logger_file.cc +++ b/lib/src/common/logger_file.cc @@ -35,7 +35,7 @@ logger_file::logger_file() : logfile(NULL), is_running(false), cur_length(0), ma logger_file::~logger_file() { if(is_running) { - log(new std::string("Closing log\n")); + logger::log_char("Closing log\n"); pthread_mutex_lock(&mutex); is_running = false; pthread_cond_signal(¬_empty); // wakeup thread and let it terminate @@ -64,13 +64,10 @@ void logger_file::init(std::string file, int max_length_) { start(-2); } -void logger_file::log(const char *msg) { - log(new std::string(msg)); -} - -void logger_file::log(str_ptr msg) { +void logger_file::log(unique_log_str_t msg) +{ pthread_mutex_lock(&mutex); - buffer.push_back(msg); + buffer.push_back(std::move(msg)); pthread_cond_signal(¬_empty); pthread_mutex_unlock(&mutex); } @@ -85,11 +82,11 @@ void logger_file::run_thread() { return; // Thread done. Messages in buffer will be handled in flush. } } - str_ptr s = buffer.front(); + unique_log_str_t s = std::move(buffer.front()); + int n = 0; if(logfile) - n = fprintf(logfile, "%s", s->c_str()); - delete s; + n = fprintf(logfile, "%s", s->msg); buffer.pop_front(); pthread_mutex_unlock(&mutex); if (n > 0) { @@ -111,13 +108,12 @@ void logger_file::run_thread() { } void logger_file::flush() { - std::deque::iterator it; + std::deque::iterator it; for(it=buffer.begin();it!=buffer.end();it++) { - str_ptr s = *it; + unique_log_str_t s = std::move(*it); if(logfile) - fprintf(logfile, "%s", s->c_str()); - delete s; + fprintf(logfile, "%s", s->msg); } } diff --git a/lib/test/common/logger_test.cc b/lib/test/common/logger_test.cc index 573144c6e..a63a650e0 100644 --- a/lib/test/common/logger_test.cc +++ b/lib/test/common/logger_test.cc @@ -39,7 +39,7 @@ void* thread_loop(void *a) { for(int i=0;ithread_id, i); - args->l->log(new std::string(buf)); + args->l->log_char(buf); } return NULL; } diff --git a/srsenb/src/enb.cc b/srsenb/src/enb.cc index 92c8669e0..5c03952b1 100644 --- a/srsenb/src/enb.cc +++ b/srsenb/src/enb.cc @@ -84,8 +84,8 @@ int enb::init(const all_args_t& args_) logger = &logger_stdout; } else { logger_file.init(args.log.filename, args.log.file_max_size); - logger_file.log("\n\n"); - logger_file.log(get_build_string().c_str()); + logger_file.log_char("\n\n"); + logger_file.log_char(get_build_string().c_str()); logger = &logger_file; } diff --git a/srsepc/src/main.cc b/srsepc/src/main.cc index 18a4c5d2d..bd8cab3c7 100644 --- a/srsepc/src/main.cc +++ b/srsepc/src/main.cc @@ -401,9 +401,9 @@ int main(int argc, char* argv[]) logger = &logger_stdout; } else { logger_file.init(args.log_args.filename); - logger_file.log("\n\n"); - logger_file.log(get_build_string().c_str()); - logger_file.log("\n--- Software Radio Systems EPC log ---\n\n"); + logger_file.log_char("\n\n"); + logger_file.log_char(get_build_string().c_str()); + logger_file.log_char("\n--- Software Radio Systems EPC log ---\n\n"); logger = &logger_file; } diff --git a/srsepc/src/mbms-gw/main.cc b/srsepc/src/mbms-gw/main.cc index 3f2312b18..309cc7e0a 100644 --- a/srsepc/src/mbms-gw/main.cc +++ b/srsepc/src/mbms-gw/main.cc @@ -204,7 +204,7 @@ main (int argc,char * argv[] ) logger = &logger_stdout; } else { logger_file.init(args.log_args.filename); - logger_file.log("\n--- Software Radio Systems MBMS log ---\n\n"); + logger_file.log_char("\n--- Software Radio Systems MBMS log ---\n\n"); logger = &logger_file; }