Skip to content

Commit

Permalink
[core] Caching logger enable state to avoid lengthy checks with every…
Browse files Browse the repository at this point in the history
… log call (#2858).
  • Loading branch information
ethouris committed Jan 18, 2024
1 parent c506764 commit d9069a5
Show file tree
Hide file tree
Showing 5 changed files with 235 additions and 160 deletions.
5 changes: 5 additions & 0 deletions srtcore/api.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -4639,25 +4639,29 @@ 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<LogFA> 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)
Expand All @@ -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)
Expand Down
122 changes: 0 additions & 122 deletions srtcore/common.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -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)

1 change: 1 addition & 0 deletions srtcore/filelist.maf
Original file line number Diff line number Diff line change
Expand Up @@ -16,6 +16,7 @@ handshake.cpp
list.cpp
logger_default.cpp
logger_defs.cpp
logging.cpp
md5.cpp
packet.cpp
packetfilter.cpp
Expand Down
212 changes: 212 additions & 0 deletions srtcore/logging.cpp
Original file line number Diff line number Diff line change
@@ -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<LogDispatcher*>::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<LogDispatcher*>::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<LogDispatcher*>::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)

Loading

0 comments on commit d9069a5

Please sign in to comment.