Skip to content

Commit

Permalink
Refactor to recover lost performance
Browse files Browse the repository at this point in the history
  • Loading branch information
@stephen-webb
stephen-webb committed Jul 23, 2024
1 parent 4b8133a commit 92bd7dc
Show file tree
Hide file tree
Showing 4 changed files with 116 additions and 117 deletions.
132 changes: 31 additions & 101 deletions src/main/cpp/loggingevent.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -28,28 +28,23 @@
#endif
#include <log4cxx/helpers/aprinitializer.h>
#include <log4cxx/helpers/threadspecificdata.h>
#include <log4cxx/helpers/transcoder.h>

#include <apr_portable.h>
#include <apr_strings.h>
#include <log4cxx/helpers/stringhelper.h>
#include <log4cxx/helpers/bytebuffer.h>
#include <log4cxx/logger.h>
#include <log4cxx/private/log4cxx_private.h>
#include <log4cxx/helpers/date.h>
#include <log4cxx/helpers/optional.h>
#include <thread>

using namespace LOG4CXX_NS;
using namespace LOG4CXX_NS::spi;
using namespace LOG4CXX_NS::helpers;

struct LoggingEvent::LoggingEventPrivate
{
LoggingEventPrivate() :
LoggingEventPrivate(const ThreadSpecificData::NamePairPtr& p = ThreadSpecificData::getCurrentData()->getNames()) :
timeStamp(0),
threadName(getCurrentThreadName()),
threadUserName(getCurrentThreadUserName())
#if LOG4CXX_ABI_VERSION <= 15
threadName(p->idString),
threadUserName(p->threadName),
#endif
pNames(p)
{
}

Expand All @@ -58,29 +53,38 @@ struct LoggingEvent::LoggingEventPrivate
, const LevelPtr& level1
, const LocationInfo& locationInfo1
, LogString&& message1
, const ThreadSpecificData::NamePairPtr& p = ThreadSpecificData::getCurrentData()->getNames()
) :
logger(logger1),
level(level1),
message(std::move(message1)),
timeStamp(Date::currentTime()),
locationInfo(locationInfo1),
threadName(getCurrentThreadName()),
threadUserName(getCurrentThreadUserName()),
chronoTimeStamp(std::chrono::microseconds(timeStamp))
#if LOG4CXX_ABI_VERSION <= 15
threadName(p->idString),
threadUserName(p->threadName),
#endif
chronoTimeStamp(std::chrono::microseconds(timeStamp)),
pNames(p)
{
}

LoggingEventPrivate(
const LogString& logger1, const LevelPtr& level1,
const LogString& message1, const LocationInfo& locationInfo1) :
const LogString& message1, const LocationInfo& locationInfo1,
const ThreadSpecificData::NamePairPtr& p = ThreadSpecificData::getCurrentData()->getNames()
) :
logger(logger1),
level(level1),
message(message1),
timeStamp(Date::currentTime()),
locationInfo(locationInfo1),
threadName(getCurrentThreadName()),
threadUserName(getCurrentThreadUserName()),
chronoTimeStamp(std::chrono::microseconds(timeStamp))
#if LOG4CXX_ABI_VERSION <= 15
threadName(p->idString),
threadUserName(p->threadName),
#endif
chronoTimeStamp(std::chrono::microseconds(timeStamp)),
pNames(p)
{
}

Expand Down Expand Up @@ -138,6 +142,7 @@ struct LoggingEvent::LoggingEventPrivate
const spi::LocationInfo locationInfo;


#if LOG4CXX_ABI_VERSION <= 15
/** The identifier of thread in which this logging event
was generated.
*/
Expand All @@ -149,24 +154,25 @@ struct LoggingEvent::LoggingEventPrivate
* systems or SetThreadDescription on Windows.
*/
const LogString& threadUserName;
#endif

std::chrono::time_point<std::chrono::system_clock> chronoTimeStamp;

/**
* This ensures the above string references remain valid
* for the lifetime of this LoggingEvent (i.e. even after thread termination).
*/
ThreadSpecificData::OtherDataPtr pNames = ThreadSpecificData::getCurrentData()->getOtherData();
ThreadSpecificData::NamePairPtr pNames;

/**
* Used to hold the diagnostic context when the lifetime
* of this LoggingEvent exceeds the duration of the logging request.
*/
struct DiagnosticContext
{
Optional<NDC::DiagnosticContext> ctx;
MDC::Map map;
};
/**
* Used to hold the diagnostic context when the lifetime
* of this LoggingEvent exceeds the duration of the logging request.
*/
mutable std::unique_ptr<DiagnosticContext> dc;
};

Expand Down Expand Up @@ -209,7 +215,7 @@ LoggingEvent::~LoggingEvent()

const LogString& LoggingEvent::getThreadUserName() const
{
return m_priv->threadUserName;
return m_priv->pNames->threadName;
}

bool LoggingEvent::getNDC(LogString& dest) const
Expand Down Expand Up @@ -311,82 +317,6 @@ LoggingEvent::KeySet LoggingEvent::getPropertyKeySet() const
return set;
}


const LogString& LoggingEvent::getCurrentThreadName()
{
LogString& thread_id_string = ThreadSpecificData::getThreadIdString();
if ( !thread_id_string.empty() )
{
return thread_id_string;
}

#if LOG4CXX_HAS_PTHREAD_SELF && !(defined(_WIN32) && defined(_LIBCPP_VERSION))
// pthread_t encoded in HEX takes needs as many characters
// as two times the size of the type, plus an additional null byte.
auto threadId = pthread_self();
char result[sizeof(pthread_t) * 3 + 10];
apr_snprintf(result, sizeof(result), LOG4CXX_APR_THREAD_FMTSPEC, (void*) &threadId);
thread_id_string = Transcoder::decode(result);
#elif defined(_WIN32)
char result[20];
apr_snprintf(result, sizeof(result), LOG4CXX_WIN32_THREAD_FMTSPEC, GetCurrentThreadId());
thread_id_string = Transcoder::decode(result);
#else
std::stringstream ss;
ss << std::hex << "0x" << std::this_thread::get_id();
thread_id_string = Transcoder::decode(ss.str().c_str());
#endif
return thread_id_string;
}

const LogString& LoggingEvent::getCurrentThreadUserName()
{
LogString& thread_name = ThreadSpecificData::getThreadName();
if( !thread_name.empty() ){
return thread_name;
}

#if LOG4CXX_HAS_PTHREAD_GETNAME && !(defined(_WIN32) && defined(_LIBCPP_VERSION))
char result[16];
pthread_t current_thread = pthread_self();
if (pthread_getname_np(current_thread, result, sizeof(result)) < 0 || 0 == result[0])
thread_name = getCurrentThreadName();
else
thread_name = Transcoder::decode(result);
#elif defined(_WIN32)
typedef HRESULT (WINAPI *TGetThreadDescription)(HANDLE, PWSTR*);
static struct initialiser
{
HMODULE hKernelBase;
TGetThreadDescription GetThreadDescription;
initialiser()
: hKernelBase(GetModuleHandleA("KernelBase.dll"))
, GetThreadDescription(nullptr)
{
if (hKernelBase)
GetThreadDescription = reinterpret_cast<TGetThreadDescription>(GetProcAddress(hKernelBase, "GetThreadDescription"));
}
} win32func;
if (win32func.GetThreadDescription)
{
PWSTR result = 0;
HRESULT hr = win32func.GetThreadDescription(GetCurrentThread(), &result);
if (SUCCEEDED(hr) && result)
{
std::wstring wresult = result;
LOG4CXX_DECODE_WCHAR(decoded, wresult);
LocalFree(result);
thread_name = decoded;
}
}
if (thread_name.empty())
thread_name = getCurrentThreadName();
#else
thread_name = getCurrentThreadName();
#endif
return thread_name;
}

void LoggingEvent::setProperty(const LogString& key, const LogString& value)
{
if (m_priv->properties == 0)
Expand Down Expand Up @@ -419,7 +349,7 @@ const LogString& LoggingEvent::getRenderedMessage() const

const LogString& LoggingEvent::getThreadName() const
{
return m_priv->threadName;
return m_priv->pNames->idString;
}

log4cxx_time_t LoggingEvent::getTimeStamp() const
Expand Down
89 changes: 78 additions & 11 deletions src/main/cpp/threadspecificdata.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -19,7 +19,10 @@
#include <log4cxx/logstring.h>
#include <log4cxx/helpers/threadspecificdata.h>
#include <log4cxx/helpers/exception.h>
#include <log4cxx/helpers/stringhelper.h>
#include <log4cxx/helpers/transcoder.h>
#include <apr_thread_proc.h>
#include <apr_strings.h>
#if !defined(LOG4CXX)
#define LOG4CXX 1
#endif
Expand All @@ -32,18 +35,17 @@
using namespace LOG4CXX_NS;
using namespace LOG4CXX_NS::helpers;

struct ThreadSpecificData::OtherData : public std::pair<LogString, LogString>
{
};

struct ThreadSpecificData::ThreadSpecificDataPrivate{
ThreadSpecificDataPrivate()
: pOtherData(std::make_shared<OtherData>())
{}
: pNamePair(std::make_shared<NamePair>())
{
setThreadIdName();
setThreadUserName();
}
NDC::Stack ndcStack;
MDC::Map mdcMap;

std::shared_ptr<OtherData> pOtherData;
std::shared_ptr<NamePair> pNamePair;

#if !LOG4CXX_LOGCHAR_IS_UNICHAR && !LOG4CXX_LOGCHAR_IS_WCHAR
std::basic_ostringstream<logchar> logchar_stringstream;
Expand All @@ -54,8 +56,73 @@ struct ThreadSpecificData::ThreadSpecificDataPrivate{
#if LOG4CXX_UNICHAR_API || LOG4CXX_LOGCHAR_IS_UNICHAR
std::basic_ostringstream<UniChar> unichar_stringstream;
#endif

void setThreadIdName();
void setThreadUserName();
};

void ThreadSpecificData::ThreadSpecificDataPrivate::setThreadIdName()
{
#if LOG4CXX_HAS_PTHREAD_SELF && !(defined(_WIN32) && defined(_LIBCPP_VERSION))
// pthread_t encoded in HEX takes needs as many characters
// as two times the size of the type, plus an additional null byte.
auto threadId = pthread_self();
char result[sizeof(pthread_t) * 3 + 10];
apr_snprintf(result, sizeof(result), LOG4CXX_APR_THREAD_FMTSPEC, (void*) &threadId);
this->pNamePair->idString = Transcoder::decode(result);
#elif defined(_WIN32)
char result[20];
apr_snprintf(result, sizeof(result), LOG4CXX_WIN32_THREAD_FMTSPEC, GetCurrentThreadId());
this->pNamePair->idString = Transcoder::decode(result);
#else
std::stringstream ss;
ss << std::hex << "0x" << std::this_thread::get_id();
this->pNamePair->idString = Transcoder::decode(ss.str().c_str());
#endif
}

void ThreadSpecificData::ThreadSpecificDataPrivate::setThreadUserName()
{
#if LOG4CXX_HAS_PTHREAD_GETNAME && !(defined(_WIN32) && defined(_LIBCPP_VERSION))
char result[16];
pthread_t current_thread = pthread_self();
if (pthread_getname_np(current_thread, result, sizeof(result)) < 0 || 0 == result[0])
this->pNamePair->threadName = this->pNamePair->idString;
else
this->pNamePair->threadName = Transcoder::decode(result);
#elif defined(_WIN32)
typedef HRESULT (WINAPI *TGetThreadDescription)(HANDLE, PWSTR*);
static struct initialiser
{
HMODULE hKernelBase;
TGetThreadDescription GetThreadDescription;
initialiser()
: hKernelBase(GetModuleHandleA("KernelBase.dll"))
, GetThreadDescription(nullptr)
{
if (hKernelBase)
GetThreadDescription = reinterpret_cast<TGetThreadDescription>(GetProcAddress(hKernelBase, "GetThreadDescription"));
}
} win32func;
if (win32func.GetThreadDescription)
{
PWSTR result = 0;
HRESULT hr = win32func.GetThreadDescription(GetCurrentThread(), &result);
if (SUCCEEDED(hr) && result)
{
std::wstring wresult = result;
LOG4CXX_DECODE_WCHAR(decoded, wresult);
LocalFree(result);
this->pNamePair->threadName = decoded;
}
}
if (this->pNamePair->threadName.empty())
this->pNamePair->threadName = this->pNamePair->idString;
#else
this->pNamePair->threadName = this->pNamePair->idString;
#endif
}

ThreadSpecificData::ThreadSpecificData()
: m_priv(std::make_unique<ThreadSpecificDataPrivate>())
{
Expand All @@ -82,17 +149,17 @@ MDC::Map& ThreadSpecificData::getMap()

LogString& ThreadSpecificData::getThreadIdString()
{
return getCurrentData()->m_priv->pOtherData->first;
return getCurrentData()->m_priv->pNamePair->idString;
}

LogString& ThreadSpecificData::getThreadName()
{
return getCurrentData()->m_priv->pOtherData->second;
return getCurrentData()->m_priv->pNamePair->threadName;
}

auto ThreadSpecificData::getOtherData() -> OtherDataPtr
auto ThreadSpecificData::getNames() -> NamePairPtr
{
return getCurrentData()->m_priv->pOtherData;
return getCurrentData()->m_priv->pNamePair;
}

#if !LOG4CXX_LOGCHAR_IS_UNICHAR && !LOG4CXX_LOGCHAR_IS_WCHAR
Expand Down
10 changes: 7 additions & 3 deletions src/main/include/log4cxx/helpers/threadspecificdata.h
View file
Original file line number Diff line number Diff line change
Expand Up @@ -61,15 +61,19 @@ class LOG4CXX_EXPORT ThreadSpecificData
static LogString& getThreadIdString();
static LogString& getThreadName();

struct NamePair
{
LogString idString;
LogString threadName;
};
using NamePairPtr = std::shared_ptr<NamePair>;
/**
* A reference counted pointer to thread specific strings.
*
* String references will remain valid
* for the lifetime of this pointer (i.e. even after thread termination).
*/
struct OtherData;
using OtherDataPtr = std::shared_ptr<OtherData>;
static OtherDataPtr getOtherData();
static NamePairPtr getNames();
private:
#if !LOG4CXX_LOGCHAR_IS_UNICHAR && !LOG4CXX_LOGCHAR_IS_WCHAR
static std::basic_ostringstream<logchar>& getStream(const logchar&);
Expand Down
2 changes: 0 additions & 2 deletions src/main/include/log4cxx/spi/loggingevent.h
View file
Original file line number Diff line number Diff line change
Expand Up @@ -212,8 +212,6 @@ class LOG4CXX_EXPORT LoggingEvent :
//
LoggingEvent(const LoggingEvent&);
LoggingEvent& operator=(const LoggingEvent&);
static const LogString& getCurrentThreadName();
static const LogString& getCurrentThreadUserName();

};

Expand Down

0 comments on commit 92bd7dc

Please sign in to comment.