Skip to content

Commit

Permalink
Remove multi-thread synchronization from CRT logger wrapper
Browse files Browse the repository at this point in the history
  • Loading branch information
SergeyRyabinin committed Mar 11, 2024
1 parent cdc553f commit 65bf755
Show file tree
Hide file tree
Showing 10 changed files with 163 additions and 192 deletions.
Original file line number Diff line number Diff line change
Expand Up @@ -24,34 +24,25 @@ namespace Aws
{
public:
DefaultCRTLogSystem(LogLevel logLevel);
virtual ~DefaultCRTLogSystem();
virtual ~DefaultCRTLogSystem() = default;

DefaultCRTLogSystem(DefaultCRTLogSystem&&) = delete;
DefaultCRTLogSystem(const DefaultCRTLogSystem&) = delete;

/**
* Gets the currently configured log level.
*/
LogLevel GetLogLevel() const override { return m_logLevel; }
LogLevel GetLogLevel() const override;
/**
* Set a new log level. This has the immediate effect of changing the log output to the new level.
*/
void SetLogLevel(LogLevel logLevel) override { m_logLevel.store(logLevel); }
void SetLogLevel(LogLevel logLevel) override;

/**
* Handle the logging information from common runtime libraries.
* Redirect them to C++ SDK logging system by default.
*/
virtual void Log(LogLevel logLevel, const char* subjectName, const char* formatStr, va_list args) override;

protected:
std::atomic<LogLevel> m_logLevel;

// destruction synchronization
mutable std::atomic<bool> m_stopLogging;
mutable std::atomic<size_t> m_logsProcessed;
mutable std::condition_variable m_stopSignal;
mutable std::mutex m_stopMutex;
};

} // namespace Logging
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -45,6 +45,11 @@ namespace Aws
*/
virtual void Log(LogLevel logLevel, const char* tag, const char* formatStr, ...) override;

/**
* Does a printf style output to ProcessFormattedStatement. Don't use this, it's unsafe. See LogStream
*/
virtual void vaLog(LogLevel logLevel, const char* tag, const char* formatStr, va_list args) override;

/**
* Writes the stream to ProcessFormattedStatement.
*/
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -36,6 +36,10 @@ namespace Aws
* Does a printf style output to the output stream. Don't use this, it's unsafe. See LogStream
*/
virtual void Log(LogLevel logLevel, const char* tag, const char* formatStr, ...) = 0;
/**
* va_list overload for Log, avoid using this as well.
*/
virtual void vaLog(LogLevel logLevel, const char* tag, const char* formatStr, va_list args) = 0;
/**
* Writes the stream to the output stream.
*/
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -36,6 +36,13 @@ namespace Aws
AWS_UNREFERENCED_PARAM(formatStr);
}

virtual void vaLog(LogLevel logLevel, const char* tag, const char* formatStr, va_list args) override
{
AWS_UNREFERENCED_PARAM(logLevel);
AWS_UNREFERENCED_PARAM(tag);
AWS_UNREFERENCED_PARAM(formatStr);
}

virtual void LogStream(LogLevel logLevel, const char* tag, const Aws::OStringStream &messageStream) override
{
AWS_UNREFERENCED_PARAM(logLevel);
Expand Down
5 changes: 5 additions & 0 deletions src/aws-cpp-sdk-core/source/Globals.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -7,6 +7,7 @@
#include <aws/crt/io/TlsOptions.h>
#include <aws/crt/io/Bootstrap.h>
#include <aws/core/Globals.h>
#include <aws/core/utils/logging/LogMacros.h>
#include <aws/core/utils/EnumParseOverflowContainer.h>
#include <aws/core/utils/memory/AWSMemory.h>
#include <aws/auth/auth.h>
Expand Down Expand Up @@ -47,6 +48,10 @@ namespace Aws
void InitializeCrt()
{
g_apiHandle = Aws::New<Aws::Crt::ApiHandle>(TAG, Aws::get_aws_allocator());
AWS_FATAL_ASSERT(g_apiHandle);
auto crtVersion = g_apiHandle->GetCrtVersion();
AWS_LOGSTREAM_INFO(TAG, "Initialized AWS-CRT-CPP with version "
<< crtVersion.major << "." << crtVersion.minor << "." << crtVersion.patch);
}

void CleanupCrt()
Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1,27 @@
/**
* Copyright Amazon.com, Inc. or its affiliates. All Rights Reserved.
* SPDX-License-Identifier: Apache-2.0.
*/

#include <aws/core/utils/logging/CRTLogSystem.h>

using namespace Aws::Utils;
using namespace Aws::Utils::Logging;

namespace Aws
{
namespace Utils
{
namespace Logging
{
static_assert(Aws::Utils::Logging::LogLevel::Off == static_cast<LogLevel>(aws_log_level::AWS_LL_NONE), "Different underlying values between SDK and CRT log level enums");
static_assert(Aws::Utils::Logging::LogLevel::Fatal == static_cast<LogLevel>(aws_log_level::AWS_LL_FATAL), "Different underlying values between SDK and CRT log level enums");
static_assert(Aws::Utils::Logging::LogLevel::Error == static_cast<LogLevel>(aws_log_level::AWS_LL_ERROR), "Different underlying values between SDK and CRT log level enums");
static_assert(Aws::Utils::Logging::LogLevel::Warn == static_cast<LogLevel>(aws_log_level::AWS_LL_WARN), "Different underlying values between SDK and CRT log level enums");
static_assert(Aws::Utils::Logging::LogLevel::Info == static_cast<LogLevel>(aws_log_level::AWS_LL_INFO), "Different underlying values between SDK and CRT log level enums");
static_assert(Aws::Utils::Logging::LogLevel::Debug == static_cast<LogLevel>(aws_log_level::AWS_LL_DEBUG), "Different underlying values between SDK and CRT log level enums");
static_assert(Aws::Utils::Logging::LogLevel::Trace == static_cast<LogLevel>(aws_log_level::AWS_LL_TRACE), "Different underlying values between SDK and CRT log level enums");
}
}
}

101 changes: 28 additions & 73 deletions src/aws-cpp-sdk-core/source/utils/logging/CRTLogging.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -24,11 +24,7 @@ namespace Utils
namespace Logging {

static std::shared_ptr<CRTLogSystemInterface> CRTLogSystem(nullptr);
static Aws::Utils::Threading::ReaderWriterLock CRTLogSystemLock;

static bool s_CRTLogsRedirectionIsSet(false);
static aws_logger s_sdkCrtLogger;
static aws_logger s_previousCrtLogger;

static int s_aws_logger_redirect_log(
struct aws_logger *logger,
Expand All @@ -37,84 +33,53 @@ static int s_aws_logger_redirect_log(
const char *format, ...)
{
AWS_UNREFERENCED_PARAM(logger);
Aws::Utils::Threading::ReaderLockGuard guard(CRTLogSystemLock);
if (CRTLogSystem)
{
assert(logger->p_impl == &s_sdkCrtLogger);
Aws::Utils::Logging::LogLevel logLevel = static_cast<LogLevel>(log_level);
const char* subjectName = aws_log_subject_name(subject);
va_list args;
va_start(args, format);
CRTLogSystem->Log(logLevel, subjectName, format, args);
va_end(args);
return AWS_OP_SUCCESS;
}
else if (s_CRTLogsRedirectionIsSet)
if (!CRTLogSystem)
{
// SDK CRT logger is terminated, fallback to an original/previous CRT logger
assert(s_previousCrtLogger.vtable->log);
va_list args;
va_start(args, format);
auto ret = s_previousCrtLogger.vtable->log(&s_previousCrtLogger, log_level, subject, format, args);
va_end(args);
return ret;
return AWS_OP_ERR;
}
assert(!"Unreachable state: this method is called without redirection set");
return AWS_OP_ERR;
assert(logger->p_impl == &s_sdkCrtLogger);
Aws::Utils::Logging::LogLevel logLevel = static_cast<LogLevel>(log_level);
const char* subjectName = aws_log_subject_name(subject);
va_list args;
va_start(args, format);
CRTLogSystem->Log(logLevel, subjectName, format, args);
va_end(args);
return AWS_OP_SUCCESS;
}

static enum aws_log_level s_aws_logger_redirect_get_log_level(struct aws_logger *logger, aws_log_subject_t subject)
{
AWS_UNREFERENCED_PARAM(logger);
Aws::Utils::Threading::ReaderLockGuard guard(CRTLogSystemLock);
AWS_UNREFERENCED_PARAM(subject);
if (CRTLogSystem)
{
assert(logger->p_impl == &s_sdkCrtLogger);
return (aws_log_level) (CRTLogSystem->GetLogLevel());
}
else if (s_CRTLogsRedirectionIsSet)
{
assert(s_previousCrtLogger.vtable->get_log_level);
return s_previousCrtLogger.vtable->get_log_level(&s_previousCrtLogger, subject);
}
assert(!"Unreachable state: this method is called without redirection set");
return AWS_LL_NONE;
}

static void s_aws_logger_redirect_clean_up(struct aws_logger *logger)
{
AWS_UNREFERENCED_PARAM(logger);
Aws::Utils::Threading::ReaderLockGuard guard(CRTLogSystemLock);
if (CRTLogSystem)
{
assert(logger->p_impl == &s_sdkCrtLogger);
return CRTLogSystem->CleanUp();
}
else if (s_CRTLogsRedirectionIsSet)
{
assert(s_previousCrtLogger.vtable->clean_up);
return s_previousCrtLogger.vtable->clean_up(&s_previousCrtLogger);
}
assert(!"Unreachable state: this method is called without redirection set");
}

static int s_aws_logger_redirect_set_log_level(struct aws_logger *logger, enum aws_log_level log_level)
{
AWS_UNREFERENCED_PARAM(logger);
Aws::Utils::Threading::ReaderLockGuard guard(CRTLogSystemLock);
if (CRTLogSystem)
{
assert(logger->p_impl == &s_sdkCrtLogger);
CRTLogSystem->SetLogLevel(static_cast<LogLevel>(log_level));
return AWS_OP_SUCCESS;
}
else if (s_CRTLogsRedirectionIsSet)
if (!CRTLogSystem)
{
assert(s_previousCrtLogger.vtable->set_log_level);
return s_previousCrtLogger.vtable->set_log_level(&s_previousCrtLogger, log_level);
return AWS_OP_ERR;
}
assert(!"Unreachable state: this method is called without redirection set");
return AWS_OP_ERR;
assert(logger->p_impl == &s_sdkCrtLogger);
CRTLogSystem->SetLogLevel(static_cast<LogLevel>(log_level));
return AWS_OP_SUCCESS;

}

static struct aws_logger_vtable s_aws_logger_redirect_vtable = {
Expand All @@ -128,39 +93,29 @@ static struct aws_logger_vtable s_aws_logger_redirect_vtable = {
/**
* Installs SDK wrapper over CRT logger.
* This wrapper will redirect all CRT logger calls to the set SDK "CRTLogSystem"
* (or back to an original CRT logger if SDK API is terminated).
* This method is not thread-safe (as the most other global Init/Shutdown APIs of the SDK).
*/
void SetUpCrtLogsRedirection()
{
if (!s_CRTLogsRedirectionIsSet)
{
static std::once_flag flag;
std::call_once(flag, [&]()
{
s_sdkCrtLogger.vtable = &s_aws_logger_redirect_vtable;
s_sdkCrtLogger.allocator = Aws::get_aws_allocator();
s_sdkCrtLogger.p_impl = &s_sdkCrtLogger;

auto pPrevLogger = aws_logger_get();
if (pPrevLogger) {
s_previousCrtLogger = *pPrevLogger;
}
aws_logger_set(&s_sdkCrtLogger);
s_CRTLogsRedirectionIsSet = true;
});
}
s_sdkCrtLogger.vtable = &s_aws_logger_redirect_vtable;
s_sdkCrtLogger.allocator = Aws::get_aws_allocator();
s_sdkCrtLogger.p_impl = &s_sdkCrtLogger;

aws_logger_set(&s_sdkCrtLogger);
}

void InitializeCRTLogging(const std::shared_ptr<CRTLogSystemInterface>& inputCrtLogSystem) {
Aws::Utils::Threading::WriterLockGuard g(CRTLogSystemLock);
SetUpCrtLogsRedirection();
CRTLogSystem = inputCrtLogSystem;
}

void ShutdownCRTLogging() {
Aws::Utils::Threading::WriterLockGuard g(CRTLogSystemLock);
CRTLogSystem.reset();
// GetLogSystem returns a raw pointer
// so this is a hack to let all other threads finish their log statement after getting a LogSystem pointer
// otherwise we would need to perform ref-counting on each logging statement
auto tmpLogger = std::move(CRTLogSystem);
std::this_thread::sleep_for(std::chrono::milliseconds(1));
tmpLogger.reset();
}

} // namespace Logging
Expand Down
57 changes: 16 additions & 41 deletions src/aws-cpp-sdk-core/source/utils/logging/DefaultCRTLogSystem.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -22,57 +22,32 @@ namespace Aws
{
namespace Logging
{
DefaultCRTLogSystem::DefaultCRTLogSystem(LogLevel logLevel) :
m_logLevel(logLevel),
m_stopLogging(false),
m_logsProcessed(0)
DefaultCRTLogSystem::DefaultCRTLogSystem(LogLevel logLevel)
{
AWS_UNREFERENCED_PARAM(logLevel); // will use one from the main SDK logger
}

DefaultCRTLogSystem::~DefaultCRTLogSystem()
LogLevel DefaultCRTLogSystem::GetLogLevel() const
{
m_stopLogging = true;
LogSystemInterface* pLogSystem = Logging::GetLogSystem();
if (pLogSystem)
{
return pLogSystem->GetLogLevel();
}
return Aws::Utils::Logging::LogLevel::Off;
}

// Allow all other threads running Log(...) to return
std::unique_lock<std::mutex> lock(m_stopMutex);
m_stopSignal.wait_for(lock,
std::chrono::milliseconds(200),
[&](){ return m_logsProcessed.load() == 0; });
void DefaultCRTLogSystem::SetLogLevel(LogLevel logLevel)
{
AWS_UNREFERENCED_PARAM(logLevel); // will use one from the main SDK logger
}

void DefaultCRTLogSystem::Log(LogLevel logLevel, const char* subjectName, const char* formatStr, va_list args)
{
if(m_stopLogging)
{
return;
}
m_logsProcessed++;
va_list tmp_args;
va_copy(tmp_args, args);
#ifdef _WIN32
const int requiredLength = _vscprintf(formatStr, tmp_args) + 1;
#else
const int requiredLength = vsnprintf(nullptr, 0, formatStr, tmp_args) + 1;
#endif
va_end(tmp_args);

Aws::OStringStream logStream;
if (requiredLength > 1)
{
Array<char> outputBuff(requiredLength);
#ifdef _WIN32
vsnprintf_s(outputBuff.GetUnderlyingData(), requiredLength, _TRUNCATE, formatStr, args);
#else
vsnprintf(outputBuff.GetUnderlyingData(), requiredLength, formatStr, args);
#endif // _WIN32
logStream << outputBuff.GetUnderlyingData();
}
Logging::GetLogSystem()->LogStream(logLevel, subjectName, logStream);
m_logsProcessed--;
if(m_logsProcessed == 0 && m_stopLogging)
LogSystemInterface* pLogSystem = Logging::GetLogSystem();
if (pLogSystem)
{
std::unique_lock<std::mutex> lock(m_stopMutex);
m_stopSignal.notify_all();
pLogSystem->vaLog(logLevel, subjectName, formatStr, args);
}
}
}
Expand Down
Loading

0 comments on commit 65bf755

Please sign in to comment.