diff --git a/srtcore/api.cpp b/srtcore/api.cpp index 7ec8ff570..a0e59ded9 100644 --- a/srtcore/api.cpp +++ b/srtcore/api.cpp @@ -4639,18 +4639,21 @@ void setloglevel(LogLevel::type ll) { ScopedLock gg(srt_logger_config.mutex); srt_logger_config.max_level = ll; + srt_logger_config.updateLoggersState(); } void addlogfa(LogFA fa) { ScopedLock gg(srt_logger_config.mutex); srt_logger_config.enabled_fa.set(fa, true); + srt_logger_config.updateLoggersState(); } void dellogfa(LogFA fa) { ScopedLock gg(srt_logger_config.mutex); srt_logger_config.enabled_fa.set(fa, false); + srt_logger_config.updateLoggersState(); } void resetlogfa(set fas) @@ -4658,6 +4661,7 @@ void resetlogfa(set fas) ScopedLock gg(srt_logger_config.mutex); for (int i = 0; i <= SRT_LOGFA_LASTNONE; ++i) srt_logger_config.enabled_fa.set(i, fas.count(i)); + srt_logger_config.updateLoggersState(); } void resetlogfa(const int* fara, size_t fara_size) @@ -4666,6 +4670,7 @@ void resetlogfa(const int* fara, size_t fara_size) srt_logger_config.enabled_fa.reset(); for (const int* i = fara; i != fara + fara_size; ++i) srt_logger_config.enabled_fa.set(*i, true); + srt_logger_config.updateLoggersState(); } void setlogstream(std::ostream& stream) diff --git a/srtcore/common.cpp b/srtcore/common.cpp index dc60b3db7..fe5217dfd 100644 --- a/srtcore/common.cpp +++ b/srtcore/common.cpp @@ -525,128 +525,6 @@ std::string MemberStatusStr(SRT_MEMBERSTATUS s) } #endif -// Logging system implementation - -#if ENABLE_LOGGING - -srt::logging::LogDispatcher::Proxy::Proxy(LogDispatcher& guy) : that(guy), that_enabled(that.CheckEnabled()) -{ - if (that_enabled) - { - i_file = ""; - i_line = 0; - flags = that.src_config->flags; - // Create logger prefix - that.CreateLogLinePrefix(os); - } -} - -LogDispatcher::Proxy LogDispatcher::operator()() -{ - return Proxy(*this); -} - -void LogDispatcher::CreateLogLinePrefix(std::ostringstream& serr) -{ - using namespace std; - using namespace srt; - - SRT_STATIC_ASSERT(ThreadName::BUFSIZE >= sizeof("hh:mm:ss.") * 2, // multiply 2 for some margin - "ThreadName::BUFSIZE is too small to be used for strftime"); - char tmp_buf[ThreadName::BUFSIZE]; - if ( !isset(SRT_LOGF_DISABLE_TIME) ) - { - // Not necessary if sending through the queue. - timeval tv; - gettimeofday(&tv, NULL); - struct tm tm = SysLocalTime((time_t) tv.tv_sec); - - if (strftime(tmp_buf, sizeof(tmp_buf), "%X.", &tm)) - { - serr << tmp_buf << setw(6) << setfill('0') << tv.tv_usec; - } - } - - string out_prefix; - if ( !isset(SRT_LOGF_DISABLE_SEVERITY) ) - { - out_prefix = prefix; - } - - // Note: ThreadName::get needs a buffer of size min. ThreadName::BUFSIZE - if ( !isset(SRT_LOGF_DISABLE_THREADNAME) && ThreadName::get(tmp_buf) ) - { - serr << "/" << tmp_buf << out_prefix << ": "; - } - else - { - serr << out_prefix << ": "; - } -} - -std::string LogDispatcher::Proxy::ExtractName(std::string pretty_function) -{ - if ( pretty_function == "" ) - return ""; - size_t pos = pretty_function.find('('); - if ( pos == std::string::npos ) - return pretty_function; // return unchanged. - - pretty_function = pretty_function.substr(0, pos); - - // There are also template instantiations where the instantiating - // parameters are encrypted inside. Therefore, search for the first - // open < and if found, search for symmetric >. - - int depth = 1; - pos = pretty_function.find('<'); - if ( pos != std::string::npos ) - { - size_t end = pos+1; - for(;;) - { - ++pos; - if ( pos == pretty_function.size() ) - { - --pos; - break; - } - if ( pretty_function[pos] == '<' ) - { - ++depth; - continue; - } - - if ( pretty_function[pos] == '>' ) - { - --depth; - if ( depth <= 0 ) - break; - continue; - } - } - - std::string afterpart = pretty_function.substr(pos+1); - pretty_function = pretty_function.substr(0, end) + ">" + afterpart; - } - - // Now see how many :: can be found in the name. - // If this occurs more than once, take the last two. - pos = pretty_function.rfind("::"); - - if ( pos == std::string::npos || pos < 2 ) - return pretty_function; // return whatever this is. No scope name. - - // Find the next occurrence of :: - if found, copy up to it. If not, - // return whatever is found. - pos -= 2; - pos = pretty_function.rfind("::", pos); - if ( pos == std::string::npos ) - return pretty_function; // nothing to cut - - return pretty_function.substr(pos+2); -} -#endif } // (end namespace srt_logging) diff --git a/srtcore/filelist.maf b/srtcore/filelist.maf index 512e3524d..e801c8b7f 100644 --- a/srtcore/filelist.maf +++ b/srtcore/filelist.maf @@ -16,6 +16,7 @@ handshake.cpp list.cpp logger_default.cpp logger_defs.cpp +logging.cpp md5.cpp packet.cpp packetfilter.cpp diff --git a/srtcore/logging.cpp b/srtcore/logging.cpp new file mode 100644 index 000000000..d309b1b8a --- /dev/null +++ b/srtcore/logging.cpp @@ -0,0 +1,212 @@ +/* + * SRT - Secure, Reliable, Transport + * Copyright (c) 2018 Haivision Systems Inc. + * + * This Source Code Form is subject to the terms of the Mozilla Public + * License, v. 2.0. If a copy of the MPL was not distributed with this + * file, You can obtain one at http://mozilla.org/MPL/2.0/. + * + */ + +/***************************************************************************** +written by + Haivision Systems Inc. + *****************************************************************************/ + + + +#include "logging.h" + +using namespace std; + + +namespace srt_logging +{ + +// Note: subscribe() and unsubscribe() functions are being called +// in the global constructor and destructor only, as the +// Logger objects (and inside them also their LogDispatcher) +// are being created. It's not predicted that LogDispatcher +// object are going to be created any other way than as +// global objects. Therefore the construction and destruction +// of them happens always in the main thread. + +void LogConfig::subscribe(LogDispatcher* lg) +{ + vector::iterator p = std::find(loggers.begin(), loggers.end(), lg); + if (p != loggers.end()) + return; // Do not register twice + + loggers.push_back(lg); +} + +void LogConfig::unsubscribe(LogDispatcher* lg) +{ + vector::iterator p = std::find(loggers.begin(), loggers.end(), lg); + if (p != loggers.end()) + { + loggers.erase(p); + } +} + +// This function doesn't have any protection on itself, +// however the API functions from which it is called, call +// it already under a mutex protection. +void LogConfig::updateLoggersState() +{ + for (vector::iterator p = loggers.begin(); + p != loggers.end(); ++p) + { + (*p)->Update(); + } +} + +void LogDispatcher::Update() +{ + bool enabled_in_fa = src_config->enabled_fa[fa]; + enabled = enabled_in_fa && level <= src_config->max_level; +} + + +// SendLogLine can be compiled normally. It's intermediately used by: +// - Proxy object, which is replaced by DummyProxy when !ENABLE_LOGGING +// - PrintLogLine, which has empty body when !ENABLE_LOGGING +void LogDispatcher::SendLogLine(const char* file, int line, const std::string& area, const std::string& msg) +{ + src_config->lock(); + if ( src_config->loghandler_fn ) + { + (*src_config->loghandler_fn)(src_config->loghandler_opaque, int(level), file, line, area.c_str(), msg.c_str()); + } + else if ( src_config->log_stream ) + { + (*src_config->log_stream) << msg; + src_config->log_stream->flush(); + } + src_config->unlock(); +} + + +#if ENABLE_LOGGING + +LogDispatcher::Proxy::Proxy(LogDispatcher& guy) : that(guy), that_enabled(that.CheckEnabled()) +{ + if (that_enabled) + { + i_file = ""; + i_line = 0; + flags = that.src_config->flags; + // Create logger prefix + that.CreateLogLinePrefix(os); + } +} + +LogDispatcher::Proxy LogDispatcher::operator()() +{ + return Proxy(*this); +} + +void LogDispatcher::CreateLogLinePrefix(std::ostringstream& serr) +{ + using namespace std; + using namespace srt; + + SRT_STATIC_ASSERT(ThreadName::BUFSIZE >= sizeof("hh:mm:ss.") * 2, // multiply 2 for some margin + "ThreadName::BUFSIZE is too small to be used for strftime"); + char tmp_buf[ThreadName::BUFSIZE]; + if ( !isset(SRT_LOGF_DISABLE_TIME) ) + { + // Not necessary if sending through the queue. + timeval tv; + gettimeofday(&tv, NULL); + struct tm tm = SysLocalTime((time_t) tv.tv_sec); + + if (strftime(tmp_buf, sizeof(tmp_buf), "%X.", &tm)) + { + serr << tmp_buf << setw(6) << setfill('0') << tv.tv_usec; + } + } + + string out_prefix; + if ( !isset(SRT_LOGF_DISABLE_SEVERITY) ) + { + out_prefix = prefix; + } + + // Note: ThreadName::get needs a buffer of size min. ThreadName::BUFSIZE + if ( !isset(SRT_LOGF_DISABLE_THREADNAME) && ThreadName::get(tmp_buf) ) + { + serr << "/" << tmp_buf << out_prefix << ": "; + } + else + { + serr << out_prefix << ": "; + } +} + +std::string LogDispatcher::Proxy::ExtractName(std::string pretty_function) +{ + if ( pretty_function == "" ) + return ""; + size_t pos = pretty_function.find('('); + if ( pos == std::string::npos ) + return pretty_function; // return unchanged. + + pretty_function = pretty_function.substr(0, pos); + + // There are also template instantiations where the instantiating + // parameters are encrypted inside. Therefore, search for the first + // open < and if found, search for symmetric >. + + int depth = 1; + pos = pretty_function.find('<'); + if ( pos != std::string::npos ) + { + size_t end = pos+1; + for(;;) + { + ++pos; + if ( pos == pretty_function.size() ) + { + --pos; + break; + } + if ( pretty_function[pos] == '<' ) + { + ++depth; + continue; + } + + if ( pretty_function[pos] == '>' ) + { + --depth; + if ( depth <= 0 ) + break; + continue; + } + } + + std::string afterpart = pretty_function.substr(pos+1); + pretty_function = pretty_function.substr(0, end) + ">" + afterpart; + } + + // Now see how many :: can be found in the name. + // If this occurs more than once, take the last two. + pos = pretty_function.rfind("::"); + + if ( pos == std::string::npos || pos < 2 ) + return pretty_function; // return whatever this is. No scope name. + + // Find the next occurrence of :: - if found, copy up to it. If not, + // return whatever is found. + pos -= 2; + pos = pretty_function.rfind("::", pos); + if ( pos == std::string::npos ) + return pretty_function; // nothing to cut + + return pretty_function.substr(pos+2); +} +#endif + +} // (end namespace srt_logging) + diff --git a/srtcore/logging.h b/srtcore/logging.h index 5867c41ae..608234eab 100644 --- a/srtcore/logging.h +++ b/srtcore/logging.h @@ -20,6 +20,7 @@ written by #include #include #include +#include #include #include #ifdef _WIN32 @@ -115,6 +116,7 @@ struct LogConfig void* loghandler_opaque; srt::sync::Mutex mutex; int flags; + std::vector loggers; LogConfig(const fa_bitset_t& efa, LogLevel::type l = LogLevel::warning, @@ -137,6 +139,10 @@ struct LogConfig SRT_ATTR_RELEASE(mutex) void unlock() { mutex.unlock(); } + + void subscribe(LogDispatcher*); + void unsubscribe(LogDispatcher*); + void updateLoggersState(); }; // The LogDispatcher class represents the object that is responsible for @@ -148,6 +154,7 @@ struct SRT_API LogDispatcher LogLevel::type level; static const size_t MAX_PREFIX_SIZE = 32; char prefix[MAX_PREFIX_SIZE+1]; + bool enabled; LogConfig* src_config; bool isset(int flg) { return (src_config->flags & flg) != 0; } @@ -158,6 +165,7 @@ struct SRT_API LogDispatcher const char* logger_pfx /*[[nullable]]*/, LogConfig& config): fa(functional_area), level(log_level), + enabled(false), src_config(&config) { // XXX stpcpy desired, but not enough portable @@ -185,13 +193,18 @@ struct SRT_API LogDispatcher prefix[MAX_PREFIX_SIZE] = '\0'; #endif } + config.subscribe(this); + Update(); } ~LogDispatcher() { + src_config->unsubscribe(this); } - bool CheckEnabled(); + void Update(); + + bool CheckEnabled() { return enabled; } void CreateLogLinePrefix(std::ostringstream&); void SendLogLine(const char* file, int line, const std::string& area, const std::string& sl); @@ -413,25 +426,8 @@ class Logger Fatal ( m_fa, LogLevel::fatal, "!!FATAL!!", logger_pfx, m_config ) { } - }; -inline bool LogDispatcher::CheckEnabled() -{ - // Don't use enabler caching. Check enabled state every time. - - // These assume to be atomically read, so the lock is not needed - // (note that writing to this field is still mutex-protected). - // It's also no problem if the level was changed at the moment - // when the enabler check is tested here. Worst case, the log - // will be printed just a moment after it was turned off. - const LogConfig* config = src_config; // to enforce using const operator[] - int configured_enabled_fa = config->enabled_fa[fa]; - int configured_maxlevel = config->max_level; - - return configured_enabled_fa && level <= configured_maxlevel; -} - #if HAVE_CXX11 @@ -462,7 +458,7 @@ inline void LogDispatcher::PrintLogLine(const char* file SRT_ATR_UNUSED, int lin #endif } -#else +#else // !HAVE_CXX11 template inline void LogDispatcher::PrintLogLine(const char* file SRT_ATR_UNUSED, int line SRT_ATR_UNUSED, const std::string& area SRT_ATR_UNUSED, const Arg& arg SRT_ATR_UNUSED) @@ -480,26 +476,9 @@ inline void LogDispatcher::PrintLogLine(const char* file SRT_ATR_UNUSED, int lin #endif } -#endif +#endif // HAVE_CXX11 -// SendLogLine can be compiled normally. It's intermediately used by: -// - Proxy object, which is replaced by DummyProxy when !ENABLE_LOGGING -// - PrintLogLine, which has empty body when !ENABLE_LOGGING -inline void LogDispatcher::SendLogLine(const char* file, int line, const std::string& area, const std::string& msg) -{ - src_config->lock(); - if ( src_config->loghandler_fn ) - { - (*src_config->loghandler_fn)(src_config->loghandler_opaque, int(level), file, line, area.c_str(), msg.c_str()); - } - else if ( src_config->log_stream ) - { - (*src_config->log_stream) << msg; - (*src_config->log_stream).flush(); - } - src_config->unlock(); } -} +#endif // INC_SRT_LOGGING_H -#endif