This is an automated email from the ASF dual-hosted git repository.
swebb2066 pushed a commit to branch master
in repository https://gitbox.apache.org/repos/asf/logging-log4cxx.git
The following commit(s) were added to refs/heads/master by this push:
new 568055f2 Allow binary-to-text conversion to be moved to a background
thread (#548)
568055f2 is described below
commit 568055f25e59f11f23a28d1dd076dce61e554506
Author: Stephen Webb <[email protected]>
AuthorDate: Fri Oct 3 10:20:01 2025 +1000
Allow binary-to-text conversion to be moved to a background thread (#548)
---
src/main/cpp/CMakeLists.txt | 1 +
src/main/cpp/asyncappender.cpp | 2 +-
src/main/cpp/asyncbuffer.cpp | 85 ++++++++
src/main/cpp/fmtlayout.cpp | 7 +-
src/main/cpp/htmllayout.cpp | 5 +-
src/main/cpp/jsonlayout.cpp | 5 +-
src/main/cpp/logger.cpp | 39 ++++
src/main/cpp/loggingevent.cpp | 49 +++++
src/main/cpp/messagebuffer.cpp | 12 +-
src/main/cpp/patternlayout.cpp | 3 +-
src/main/cpp/telnetappender.cpp | 2 +-
src/main/cpp/xmllayout.cpp | 5 +-
src/main/include/log4cxx/helpers/asyncbuffer.h | 274 +++++++++++++++++++++++++
src/main/include/log4cxx/logger.h | 59 ++++++
src/main/include/log4cxx/spi/loggingevent.h | 20 ++
src/site/markdown/change-report-gh.md | 2 +
src/site/markdown/performance.md | 7 +-
src/test/cpp/asyncappendertestcase.cpp | 94 ++++++---
src/test/cpp/benchmark/benchmark.cpp | 69 +++++--
19 files changed, 673 insertions(+), 67 deletions(-)
diff --git a/src/main/cpp/CMakeLists.txt b/src/main/cpp/CMakeLists.txt
index 465a51d8..8a2526f4 100644
--- a/src/main/cpp/CMakeLists.txt
+++ b/src/main/cpp/CMakeLists.txt
@@ -78,6 +78,7 @@ target_sources(log4cxx
appenderskeleton.cpp
aprinitializer.cpp
asyncappender.cpp
+ asyncbuffer.cpp
basicconfigurator.cpp
bufferedwriter.cpp
bytearrayinputstream.cpp
diff --git a/src/main/cpp/asyncappender.cpp b/src/main/cpp/asyncappender.cpp
index 2427cb62..d199e392 100644
--- a/src/main/cpp/asyncappender.cpp
+++ b/src/main/cpp/asyncappender.cpp
@@ -498,7 +498,7 @@ LoggingEventPtr DiscardSummary::createEvent(Pool& p)
LogString msg(LOG4CXX_STR("Discarded "));
StringHelper::toString(count, p, msg);
msg.append(LOG4CXX_STR(" messages due to a full event buffer including:
"));
- msg.append(maxEvent->getMessage());
+ msg.append(maxEvent->getRenderedMessage());
return std::make_shared<LoggingEvent>(
maxEvent->getLoggerName(),
maxEvent->getLevel(),
diff --git a/src/main/cpp/asyncbuffer.cpp b/src/main/cpp/asyncbuffer.cpp
new file mode 100644
index 00000000..b7e5daf5
--- /dev/null
+++ b/src/main/cpp/asyncbuffer.cpp
@@ -0,0 +1,85 @@
+/*
+ * Licensed to the Apache Software Foundation (ASF) under one or more
+ * contributor license agreements. See the NOTICE file distributed with
+ * this work for additional information regarding copyright ownership.
+ * The ASF licenses this file to You under the Apache License, Version 2.0
+ * (the "License"); you may not use this file except in compliance with
+ * the License. You may obtain a copy of the License at
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+#include <log4cxx/helpers/asyncbuffer.h>
+
+namespace LOG4CXX_NS
+{
+
+namespace helpers
+{
+
+struct AsyncBuffer::Private
+{
+ std::vector<MessageBufferAppender> data;
+};
+
+/** An empty buffer.
+*/
+AsyncBuffer::AsyncBuffer()
+{}
+
+/** A new buffer with the content of \c other
+*/
+AsyncBuffer::AsyncBuffer(AsyncBuffer&& other)
+ : m_priv(std::move(other.m_priv))
+{
+}
+
+/** Release resources.
+*/
+AsyncBuffer::~AsyncBuffer()
+{
+}
+
+/**
+* Has no item been added to this?
+*/
+bool AsyncBuffer::empty() const { return !m_priv || m_priv->data.empty(); }
+
+/**
+* Add text version of buffered values to \c msg
+*/
+void AsyncBuffer::renderMessage(LogCharMessageBuffer& msg)
+{
+ if (m_priv)
+ for (auto& renderer : m_priv->data)
+ renderer(msg);
+}
+
+/**
+* Remove all message appenders
+*/
+void AsyncBuffer::clear()
+{
+ if (m_priv)
+ m_priv->data.clear();
+}
+
+/**
+ * Append \c function to this buffer.
+ */
+void AsyncBuffer::append(const MessageBufferAppender& f)
+{
+ if (!m_priv)
+ m_priv = std::make_unique<Private>();
+ m_priv->data.push_back(f);
+}
+
+} // namespace helpers
+} // namespace LOG4CXX_NS
+
diff --git a/src/main/cpp/fmtlayout.cpp b/src/main/cpp/fmtlayout.cpp
index faa0d0c9..e6c5bf77 100644
--- a/src/main/cpp/fmtlayout.cpp
+++ b/src/main/cpp/fmtlayout.cpp
@@ -89,7 +89,8 @@ void FMTLayout::format(LogString& output,
const spi::LoggingEventPtr& event,
LOG4CXX_NS::helpers::Pool&) const
{
- output.reserve(m_priv->expectedPatternLength +
event->getMessage().size());
+ auto& lsMsg = event->getRenderedMessage();
+ output.reserve(m_priv->expectedPatternLength + lsMsg.size());
auto locationFull = fmt::format("{}({})",
event->getLocationInformation().getFileName(),
event->getLocationInformation().getLineNumber());
@@ -100,7 +101,7 @@ void FMTLayout::format(LogString& output,
LOG4CXX_ENCODE_CHAR(sPattern, m_priv->conversionPattern);
LOG4CXX_ENCODE_CHAR(sLogger, event->getLoggerName());
LOG4CXX_ENCODE_CHAR(sLevel, event->getLevel()->toString());
- LOG4CXX_ENCODE_CHAR(sMsg, event->getMessage());
+ LOG4CXX_ENCODE_CHAR(sMsg, lsMsg);
LOG4CXX_ENCODE_CHAR(sThread, event->getThreadName());
LOG4CXX_ENCODE_CHAR(endOfLine, LOG4CXX_EOL);
#else
@@ -108,7 +109,7 @@ void FMTLayout::format(LogString& output,
auto& sPattern = m_priv->conversionPattern;
auto& sLogger = event->getLoggerName();
auto sLevel = event->getLevel()->toString();
- auto& sMsg = event->getMessage();
+ auto& sMsg = lsMsg;
auto& sThread = event->getThreadName();
auto endOfLine = LOG4CXX_EOL;
#endif
diff --git a/src/main/cpp/htmllayout.cpp b/src/main/cpp/htmllayout.cpp
index f1b2747c..bcfce2f1 100644
--- a/src/main/cpp/htmllayout.cpp
+++ b/src/main/cpp/htmllayout.cpp
@@ -84,7 +84,8 @@ void HTMLLayout::format(LogString& output,
const spi::LoggingEventPtr& event,
Pool& p) const
{
- output.reserve(m_priv->expectedPatternLength +
event->getMessage().size());
+ auto& lsMsg = event->getRenderedMessage();
+ output.reserve(m_priv->expectedPatternLength + lsMsg.size());
output.append(LOG4CXX_EOL);
output.append(LOG4CXX_STR("<tr>"));
output.append(LOG4CXX_EOL);
@@ -152,7 +153,7 @@ void HTMLLayout::format(LogString& output,
}
output.append(LOG4CXX_STR("<td title=\"Message\">"));
- Transform::appendEscapingTags(output, event->getRenderedMessage());
+ Transform::appendEscapingTags(output, lsMsg);
output.append(LOG4CXX_STR("</td>"));
output.append(LOG4CXX_EOL);
output.append(LOG4CXX_STR("</tr>"));
diff --git a/src/main/cpp/jsonlayout.cpp b/src/main/cpp/jsonlayout.cpp
index 9b286aff..54712359 100644
--- a/src/main/cpp/jsonlayout.cpp
+++ b/src/main/cpp/jsonlayout.cpp
@@ -132,7 +132,8 @@ void JSONLayout::format(LogString& output,
const spi::LoggingEventPtr& event,
Pool& p) const
{
- output.reserve(m_priv->expectedPatternLength +
event->getMessage().size());
+ auto& lsMsg = event->getRenderedMessage();
+ output.reserve(m_priv->expectedPatternLength + lsMsg.size());
output.append(LOG4CXX_STR("{"));
output.append(m_priv->prettyPrint ? LOG4CXX_EOL : LOG4CXX_STR(" "));
@@ -187,7 +188,7 @@ void JSONLayout::format(LogString& output,
}
output.append(LOG4CXX_STR("\"message\": "));
- appendQuotedEscapedString(output, event->getMessage());
+ appendQuotedEscapedString(output, lsMsg);
appendSerializedMDC(output, event);
appendSerializedNDC(output, event);
diff --git a/src/main/cpp/logger.cpp b/src/main/cpp/logger.cpp
index e814620f..9574a149 100644
--- a/src/main/cpp/logger.cpp
+++ b/src/main/cpp/logger.cpp
@@ -173,6 +173,15 @@ void Logger::closeNestedAppenders()
}
}
+void Logger::addEvent(const LevelPtr& level, helpers::AsyncBuffer&&
messageAppender, const LocationInfo& location) const
+{
+ if (!getHierarchy()) // Has removeHierarchy() been called?
+ return;
+ auto event = std::make_shared<LoggingEvent>(m_priv->name, level,
location, std::move(messageAppender));
+ Pool p;
+ callAppenders(event, p);
+}
+
void Logger::addEvent(const LevelPtr& level, std::string&& message, const
LocationInfo& location) const
{
if (!getHierarchy()) // Has removeHierarchy() been called?
@@ -192,31 +201,61 @@ void Logger::addFatalEvent(std::string&& message, const
LocationInfo& location)
addEvent(m_priv->levelData->Fatal, std::move(message), location);
}
+void Logger::addFatalEvent(helpers::AsyncBuffer&& messageAppender, const
LocationInfo& location) const
+{
+ addEvent(m_priv->levelData->Fatal, std::move(messageAppender),
location);
+}
+
void Logger::addErrorEvent(std::string&& message, const LocationInfo&
location) const
{
addEvent(m_priv->levelData->Error, std::move(message), location);
}
+void Logger::addErrorEvent(helpers::AsyncBuffer&& messageAppender, const
LocationInfo& location) const
+{
+ addEvent(m_priv->levelData->Error, std::move(messageAppender),
location);
+}
+
void Logger::addWarnEvent(std::string&& message, const LocationInfo& location)
const
{
addEvent(m_priv->levelData->Warn, std::move(message), location);
}
+void Logger::addWarnEvent(helpers::AsyncBuffer&& messageAppender, const
LocationInfo& location) const
+{
+ addEvent(m_priv->levelData->Warn, std::move(messageAppender), location);
+}
+
void Logger::addInfoEvent(std::string&& message, const LocationInfo& location)
const
{
addEvent(m_priv->levelData->Info, std::move(message), location);
}
+void Logger::addInfoEvent(helpers::AsyncBuffer&& messageAppender, const
LocationInfo& location) const
+{
+ addEvent(m_priv->levelData->Info, std::move(messageAppender), location);
+}
+
void Logger::addDebugEvent(std::string&& message, const LocationInfo&
location) const
{
addEvent(m_priv->levelData->Debug, std::move(message), location);
}
+void Logger::addDebugEvent(helpers::AsyncBuffer&& messageAppender, const
LocationInfo& location) const
+{
+ addEvent(m_priv->levelData->Debug, std::move(messageAppender),
location);
+}
+
void Logger::addTraceEvent(std::string&& message, const LocationInfo&
location) const
{
addEvent(m_priv->levelData->Trace, std::move(message), location);
}
+void Logger::addTraceEvent(helpers::AsyncBuffer&& messageAppender, const
LocationInfo& location) const
+{
+ addEvent(m_priv->levelData->Trace, std::move(messageAppender),
location);
+}
+
void Logger::forcedLog(const LevelPtr& level, const std::string& message,
const LocationInfo& location) const
{
diff --git a/src/main/cpp/loggingevent.cpp b/src/main/cpp/loggingevent.cpp
index e1fc11f2..ceae144c 100644
--- a/src/main/cpp/loggingevent.cpp
+++ b/src/main/cpp/loggingevent.cpp
@@ -29,6 +29,7 @@
#include <log4cxx/helpers/aprinitializer.h>
#include <log4cxx/helpers/threadspecificdata.h>
#include <log4cxx/helpers/bytebuffer.h>
+#include <log4cxx/helpers/messagebuffer.h>
#include <log4cxx/helpers/date.h>
#include <log4cxx/helpers/optional.h>
@@ -61,6 +62,23 @@ struct LoggingEvent::LoggingEventPrivate
{
}
+ LoggingEventPrivate
+ ( const LogString& logger1
+ , const LevelPtr& level1
+ , const LocationInfo& locationInfo1
+ , helpers::AsyncBuffer&& messageAppenderArg
+ , const ThreadSpecificData::NamePairPtr p =
ThreadSpecificData::getNames()
+ )
+ : logger(logger1)
+ , level(level1)
+ , timeStamp(Date::currentTime())
+ , locationInfo(locationInfo1)
+ , chronoTimeStamp(std::chrono::microseconds(timeStamp))
+ , pNames(p)
+ , messageAppender(std::move(messageAppenderArg))
+ {
+ }
+
LoggingEventPrivate(
const LogString& logger1, const LevelPtr& level1,
const LogString& message1, const LocationInfo& locationInfo1,
@@ -124,6 +142,21 @@ struct LoggingEvent::LoggingEventPrivate
* of this LoggingEvent exceeds the duration of the logging request.
*/
mutable std::unique_ptr<DiagnosticContext> dc;
+
+ /** Application supplied message builders.
+ */
+ helpers::AsyncBuffer messageAppender;
+
+ void renderMessage()
+ {
+ if (!this->messageAppender.empty())
+ {
+ helpers::LogCharMessageBuffer buf;
+ this->messageAppender.renderMessage(buf);
+ this->message = buf.extract_str(buf);
+ this->messageAppender.clear();
+ }
+ }
};
IMPLEMENT_LOG4CXX_OBJECT(LoggingEvent)
@@ -152,6 +185,16 @@ LoggingEvent::LoggingEvent
{
}
+LoggingEvent::LoggingEvent
+ ( const LogString& logger
+ , const LevelPtr& level
+ , const LocationInfo& location
+ , helpers::AsyncBuffer&& messageAppender
+ )
+ : m_priv(std::make_unique<LoggingEventPrivate>(logger, level, location,
std::move(messageAppender)))
+{
+}
+
LoggingEvent::LoggingEvent(
const LogString& logger1, const LevelPtr& level1,
const LogString& message1, const LocationInfo& locationInfo1) :
@@ -273,6 +316,11 @@ LoggingEvent::KeySet LoggingEvent::getPropertyKeySet()
const
return set;
}
+void LoggingEvent::renderMessage()
+{
+ m_priv->renderMessage();
+}
+
void LoggingEvent::setProperty(const LogString& key, const LogString& value)
{
if (m_priv->properties == 0)
@@ -300,6 +348,7 @@ const LogString& LoggingEvent::getMessage() const
const LogString& LoggingEvent::getRenderedMessage() const
{
+ m_priv->renderMessage();
return m_priv->message;
}
diff --git a/src/main/cpp/messagebuffer.cpp b/src/main/cpp/messagebuffer.cpp
index 6c7f1a48..df908bff 100644
--- a/src/main/cpp/messagebuffer.cpp
+++ b/src/main/cpp/messagebuffer.cpp
@@ -161,7 +161,7 @@ std::basic_string<char>
CharMessageBuffer::extract_str(std::basic_ostream<char>&
std::basic_string<char> CharMessageBuffer::extract_str(CharMessageBuffer&)
{
- return std::move(m_priv->buf);
+ return std::move(m_priv->BufFromStream());
}
const std::basic_string<char>&
CharMessageBuffer::str(std::basic_ostream<char>&)
@@ -171,7 +171,7 @@ const std::basic_string<char>&
CharMessageBuffer::str(std::basic_ostream<char>&)
const std::basic_string<char>& CharMessageBuffer::str(CharMessageBuffer&)
{
- return m_priv->buf;
+ return m_priv->BufFromStream();
}
bool CharMessageBuffer::hasStream() const
@@ -306,7 +306,7 @@ std::basic_string<wchar_t>
WideMessageBuffer::extract_str(std::basic_ostream<wch
std::basic_string<wchar_t> WideMessageBuffer::extract_str(WideMessageBuffer&)
{
- return std::move(m_priv->buf);
+ return std::move(m_priv->BufFromStream());
}
const std::basic_string<wchar_t>&
WideMessageBuffer::str(std::basic_ostream<wchar_t>&)
@@ -316,7 +316,7 @@ const std::basic_string<wchar_t>&
WideMessageBuffer::str(std::basic_ostream<wcha
const std::basic_string<wchar_t>& WideMessageBuffer::str(WideMessageBuffer&)
{
- return m_priv->buf;
+ return m_priv->BufFromStream();
}
bool WideMessageBuffer::hasStream() const
@@ -672,7 +672,7 @@ std::basic_string<LOG4CXX_NS::UniChar>
UniCharMessageBuffer::extract_str(UniChar
std::basic_string<LOG4CXX_NS::UniChar>
UniCharMessageBuffer::extract_str(UniCharMessageBuffer&)
{
- return std::move(m_priv->buf);
+ return std::move(m_priv->BufFromStream());
}
const std::basic_string<LOG4CXX_NS::UniChar>&
UniCharMessageBuffer::str(UniCharMessageBuffer::uostream&)
@@ -682,7 +682,7 @@ const std::basic_string<LOG4CXX_NS::UniChar>&
UniCharMessageBuffer::str(UniCharM
const std::basic_string<LOG4CXX_NS::UniChar>&
UniCharMessageBuffer::str(UniCharMessageBuffer&)
{
- return m_priv->buf;
+ return m_priv->BufFromStream();
}
bool UniCharMessageBuffer::hasStream() const
diff --git a/src/main/cpp/patternlayout.cpp b/src/main/cpp/patternlayout.cpp
index 371e47d7..68d43c5e 100644
--- a/src/main/cpp/patternlayout.cpp
+++ b/src/main/cpp/patternlayout.cpp
@@ -122,7 +122,8 @@ void PatternLayout::format(LogString& output,
const spi::LoggingEventPtr& event,
Pool& pool) const
{
- output.reserve(m_priv->expectedPatternLength +
event->getMessage().size());
+ auto& lsMsg = event->getRenderedMessage();
+ output.reserve(m_priv->expectedPatternLength + lsMsg.size());
std::vector<FormattingInfoPtr>::const_iterator formatterIter =
m_priv->patternFields.begin();
diff --git a/src/main/cpp/telnetappender.cpp b/src/main/cpp/telnetappender.cpp
index fcacc40c..cc3b1439 100644
--- a/src/main/cpp/telnetappender.cpp
+++ b/src/main/cpp/telnetappender.cpp
@@ -230,7 +230,7 @@ void TelnetAppender::append(const spi::LoggingEventPtr&
event, Pool& p)
if (_priv->layout)
_priv->layout->format(msg, event, p);
else
- msg = event->getMessage();
+ msg = event->getRenderedMessage();
msg.append(LOG4CXX_STR("\r\n"));
size_t bytesSize = msg.size() * 2;
char* bytes = p.pstralloc(bytesSize);
diff --git a/src/main/cpp/xmllayout.cpp b/src/main/cpp/xmllayout.cpp
index 0b7fe073..e26be6c8 100644
--- a/src/main/cpp/xmllayout.cpp
+++ b/src/main/cpp/xmllayout.cpp
@@ -78,7 +78,8 @@ void XMLLayout::format(LogString& output,
const spi::LoggingEventPtr& event,
Pool& p) const
{
- output.reserve(m_priv->expectedPatternLength +
event->getMessage().size());
+ auto& lsMsg = event->getRenderedMessage();
+ output.reserve(m_priv->expectedPatternLength + lsMsg.size());
output.append(LOG4CXX_STR("<log4j:event logger=\""));
Transform::appendEscapingTags(output, event->getLoggerName());
output.append(LOG4CXX_STR("\" timestamp=\""));
@@ -93,7 +94,7 @@ void XMLLayout::format(LogString& output,
output.append(LOG4CXX_STR("<log4j:message><![CDATA["));
// Append the rendered message. Also make sure to escape any
// existing CDATA sections.
- Transform::appendEscapingCDATA(output, event->getRenderedMessage());
+ Transform::appendEscapingCDATA(output, lsMsg);
output.append(LOG4CXX_STR("]]></log4j:message>"));
output.append(LOG4CXX_EOL);
diff --git a/src/main/include/log4cxx/helpers/asyncbuffer.h
b/src/main/include/log4cxx/helpers/asyncbuffer.h
new file mode 100644
index 00000000..ebc01a04
--- /dev/null
+++ b/src/main/include/log4cxx/helpers/asyncbuffer.h
@@ -0,0 +1,274 @@
+/*
+ * Licensed to the Apache Software Foundation (ASF) under one or more
+ * contributor license agreements. See the NOTICE file distributed with
+ * this work for additional information regarding copyright ownership.
+ * The ASF licenses this file to You under the Apache License, Version 2.0
+ * (the "License"); you may not use this file except in compliance with
+ * the License. You may obtain a copy of the License at
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+#ifndef LOG4CXX_ASYNC_BUFFER_H
+#define LOG4CXX_ASYNC_BUFFER_H
+
+#include <log4cxx/helpers/messagebuffer.h>
+#include <functional>
+#include <vector>
+
+namespace LOG4CXX_NS
+{
+
+namespace helpers
+{
+
+/**
+ * This class is used by the LOG4CXX_INFO_ASYNC and similar
+ * macros to support insertion operators.
+ * The class is not intended for use outside of that context.
+ */
+class LOG4CXX_EXPORT AsyncBuffer
+{
+public:
+ /** An empty buffer.
+ */
+ AsyncBuffer();
+
+ /** A new buffer with the content of \c other
+ */
+ AsyncBuffer(AsyncBuffer&& other);
+
+ /** Release resources.
+ */
+ ~AsyncBuffer();
+
+ /** Append a function to this buffer that will convert \c value to text.
+ * @param value type must be copy-constructable
+ * @return this buffer.
+ */
+ template<typename T>
+ AsyncBuffer& operator<<(const T& value)
+ {
+ append([value](LogCharMessageBuffer& msgBuf)
+ {
+ msgBuf << value;
+ });
+ return *this;
+ }
+
+#ifdef __cpp_init_captures // C++ >= 14
+ /** Append a function to this buffer that will convert \c value to text.
+ * @param value type must be move-constructable
+ * @return this buffer.
+ */
+ template<typename T>
+ AsyncBuffer& operator<<(const T&& rvalue)
+ {
+ append([value = std::move(rvalue)](LogCharMessageBuffer& msgBuf)
+ {
+ msgBuf << value;
+ });
+ return *this;
+ }
+#endif
+ /**
+ * Has no item been added to this?
+ */
+ bool empty() const;
+
+ /**
+ * Add text version of buffered values to \c msg
+ */
+ void renderMessage(LogCharMessageBuffer& msg);
+
+ /**
+ * Remove all message appenders
+ */
+ void clear();
+
+private:
+ AsyncBuffer(const AsyncBuffer&) = delete;
+ AsyncBuffer& operator=(const AsyncBuffer&) = delete;
+
+ LOG4CXX_DECLARE_PRIVATE_MEMBER_PTR(Private, m_priv)
+ using MessageBufferAppender =
std::function<void(LogCharMessageBuffer&)>;
+
+ /**
+ * Append \c function to this buffer.
+ */
+ void append(const MessageBufferAppender& f);
+};
+
+} // namespace helpers
+} // namespace LOG4CXX_NS
+
+/** @addtogroup LoggingMacros Logging macros
+@{
+*/
+
+#if !defined(LOG4CXX_THRESHOLD) || LOG4CXX_THRESHOLD <= 10000
+/**
+Add a new logging event containing \c message to attached appender(s) if \c
logger is enabled for <code>DEBUG</code> events.
+
+\usage
+~~~{.cpp}
+LOG4CXX_DEBUG_ASYNC(m_log, "AddMesh:"
+ << " name " << meshName
+ << " type 0x" << std:: hex << traits.Type
+ << " materialName " << meshObject.GetMaterialName()
+ << " visible? " << traits.IsDefaultVisible
+ << " at " << obj->getBoundingBox().getCenter()
+ << " +/- " << obj->getBoundingBox().getHalfSize()
+ );
+~~~
+
+@param logger the logger that has the enabled status.
+@param message a valid r-value expression of an
<code>operator<<(std::ostream&. ...)</code> overload.
+
+*/
+#define LOG4CXX_DEBUG_ASYNC(logger, message) do { \
+ if
(LOG4CXX_UNLIKELY(::LOG4CXX_NS::Logger::isDebugEnabledFor(logger))) {\
+ ::LOG4CXX_NS::helpers::AsyncBuffer buf; \
+ logger->addDebugEvent(std::move(buf << message),
LOG4CXX_LOCATION); }} while (0)
+#else
+#define LOG4CXX_DEBUG_ASYNC(logger, message)
+#endif
+
+#if !defined(LOG4CXX_THRESHOLD) || LOG4CXX_THRESHOLD <= 5000
+/**
+Add a new logging event containing \c message to attached appender(s) if \c
logger is enabled for <code>TRACE</code> events.
+
+\usage
+~~~{.cpp}
+ LOG4CXX_TRACE_ASYNC(m_log, "AddVertex:" << " at " << p << " n " << n << '
' << color);
+~~~
+
+@param logger the logger that has the enabled status.
+@param message a valid r-value expression of an
<code>operator<<(std::ostream&. ...)</code> overload.
+*/
+#define LOG4CXX_TRACE_ASYNC(logger, message) do { \
+ if
(LOG4CXX_UNLIKELY(::LOG4CXX_NS::Logger::isTraceEnabledFor(logger))) {\
+ ::LOG4CXX_NS::helpers::AsyncBuffer buf; \
+ logger->addTraceEvent(std::move(buf << message),
LOG4CXX_LOCATION); }} while (0)
+#else
+#define LOG4CXX_TRACE_ASYNC(logger, message)
+#endif
+
+#if !defined(LOG4CXX_THRESHOLD) || LOG4CXX_THRESHOLD <= 20000
+/**
+Add a new logging event containing \c message to attached appender(s) if \c
logger is enabled for <code>INFO</code> events.
+
+\usage
+~~~{.cpp}
+LOG4CXX_INFO_ASYNC(m_log, surface->GetName()
+ << " successfully planned " << std::fixed << std::setprecision(1) <<
((plannedArea / (plannedArea + unplannedArea)) * 100.0) << "%"
+ << " planned area " << std::fixed << std::setprecision(4) <<
plannedArea << "m^2"
+ << " unplanned area " << unplannedArea << "m^2"
+ << " planned segments " << surface->GetSegmentPlanCount() << " of " <<
surface->GetSegmentCount()
+ );
+~~~
+
+@param logger the logger that has the enabled status.
+@param message a valid r-value expression of an
<code>operator<<(std::ostream&. ...)</code> overload.
+*/
+#define LOG4CXX_INFO_ASYNC(logger, message) do { \
+ if (::LOG4CXX_NS::Logger::isInfoEnabledFor(logger)) {\
+ ::LOG4CXX_NS::helpers::AsyncBuffer buf;\
+ logger->addInfoEvent(std::move(buf << message),
LOG4CXX_LOCATION);\
+ }} while (0)
+
+#endif
+
+#else
+#define LOG4CXX_INFO_ASYNC(logger, message)
+#endif
+
+#if !defined(LOG4CXX_THRESHOLD) || LOG4CXX_THRESHOLD <= 30000
+/**
+Add a new logging event containing \c message to attached appender(s) if \c
logger is enabled for <code>WARN</code> events.
+
+\usage
+~~~{.cpp}
+catch (const std::exception& ex)
+{
+ LOG4CXX_WARN_ASYNC(m_log, ex.what() << ": in " <<
m_task->GetParamFilePath());
+}
+~~~
+
+@param logger the logger to be used.
+@param message a valid r-value expression of an
<code>operator<<(std::ostream&. ...)</code> overload.
+*/
+#define LOG4CXX_WARN_ASYNC(logger, message) do { \
+ if (::LOG4CXX_NS::Logger::isWarnEnabledFor(logger)) {\
+ ::LOG4CXX_NS::helpers::AsyncBuffer buf; \
+ logger->addWarnEvent(std::move(buf << message),
LOG4CXX_LOCATION); }} while (0)
+#else
+#define LOG4CXX_WARN_ASYNC(logger, message)
+#endif
+
+#if !defined(LOG4CXX_THRESHOLD) || LOG4CXX_THRESHOLD <= 40000
+/**
+Add a new logging event containing \c message to attached appender(s) if \c
logger is enabled for <code>ERROR</code> events.
+
+\usage
+~~~{.cpp}
+catch (std::exception& ex)
+{
+ LOG4CXX_ERROR_ASYNC(m_log, ex.what() << " in AddScanData");
+}
+~~~
+
+@param logger the logger to be used.
+@param message a valid r-value expression of an
<code>operator<<(std::ostream&. ...)</code> overload.
+*/
+#define LOG4CXX_ERROR_ASYNC(logger, message) do { \
+ if (::LOG4CXX_NS::Logger::isErrorEnabledFor(logger)) {\
+ ::LOG4CXX_NS::helpers::AsyncBuffer buf; \
+ logger->addErrorEvent(std::move(buf << message),
LOG4CXX_LOCATION); }} while (0)
+
+/**
+If \c condition is not true, add a new logging event containing \c message to
attached appender(s) if \c logger is enabled for <code>ERROR</code> events.
+
+@param logger the logger to be used.
+@param condition condition
+@param message a valid r-value expression of an
<code>operator<<(std::ostream&. ...)</code> overload.
+*/
+#define LOG4CXX_ASSERT_ASYNC(logger, condition, message) do { \
+ if (!(condition) &&
::LOG4CXX_NS::Logger::isErrorEnabledFor(logger)) {\
+ ::LOG4CXX_NS::helpers::AsyncBuffer buf; \
+ LOG4CXX_STACKTRACE \
+ logger->addErrorEvent(std::move(buf << message),
LOG4CXX_LOCATION); }} while (0)
+
+#else
+#define LOG4CXX_ERROR_ASYNC(logger, message)
+#define LOG4CXX_ASSERT_ASYNC(logger, condition, message)
+#endif
+
+#if !defined(LOG4CXX_THRESHOLD) || LOG4CXX_THRESHOLD <= 50000
+/**
+Add a new logging event containing \c message to attached appender(s) if \c
logger is enabled for <code>FATAL</code> events.
+
+\usage
+~~~{.cpp}
+LOG4CXX_FATAL_ASYNC(m_log, m_renderSystem->getName() << " is not supported");
+~~~
+
+@param logger the logger to be used.
+@param message a valid r-value expression of an
<code>operator<<(std::ostream&. ...)</code> overload.
+*/
+#define LOG4CXX_FATAL_ASYNC(logger, message) do { \
+ if (::LOG4CXX_NS::Logger::isFatalEnabledFor(logger)) {\
+ ::LOG4CXX_NS::helpers::AsyncBuffer buf; \
+ logger->addFatalEvent(std::move(buf << message),
LOG4CXX_LOCATION); }} while (0)
+
+#else
+#define LOG4CXX_FATAL_ASYNC(logger, message)
+#endif
+
+/**@} Logging macro group */
diff --git a/src/main/include/log4cxx/logger.h
b/src/main/include/log4cxx/logger.h
index 91181504..1241d0c9 100644
--- a/src/main/include/log4cxx/logger.h
+++ b/src/main/include/log4cxx/logger.h
@@ -23,6 +23,7 @@
#include <log4cxx/helpers/pool.h>
#include <log4cxx/spi/location/locationinfo.h>
#include <log4cxx/helpers/resourcebundle.h>
+#include <log4cxx/helpers/asyncbuffer.h>
#include <log4cxx/helpers/messagebuffer.h>
namespace LOG4CXX_NS
@@ -506,6 +507,16 @@ class LOG4CXX_EXPORT Logger
void addEvent(const LevelPtr& level, std::string&& message
, const spi::LocationInfo& location =
spi::LocationInfo::getLocationUnavailable()) const;
+ /**
+ Add to attached appender(s) a new \c level LoggingEvent which
was requested at \c sourceLocation where the message is built asynchronously by
\c messageAppender
+ without further checks.
+ @param level The logging event level.
+ @param message The text to add to the logging event.
+ @param location The source code location of the logging request.
+ */
+ void addEvent(const LevelPtr& level, helpers::AsyncBuffer&&
messageAppender
+ , const spi::LocationInfo& sourceLocation =
spi::LocationInfo::getLocationUnavailable()) const;
+
/**
Add a new fatal level logging event containing \c message and
\c location to attached appender(s)
without further checks.
@@ -514,6 +525,14 @@ class LOG4CXX_EXPORT Logger
*/
void addFatalEvent(std::string&& message, const
spi::LocationInfo& location = spi::LocationInfo::getLocationUnavailable())
const;
+ /**
+ Add to attached appender(s) a new FATAL level LoggingEvent
which was requested at \c sourceLocation where the message is built
asynchronously by \c messageAppender
+ without further checks.
+ @param message The text to add to the logging event.
+ @param location The source code location of the logging request.
+ */
+ void addFatalEvent(helpers::AsyncBuffer&& messageAppender,
const spi::LocationInfo& location =
spi::LocationInfo::getLocationUnavailable()) const;
+
/**
Add a new error level logging event containing \c message and
\c location to attached appender(s)
without further checks.
@@ -522,6 +541,14 @@ class LOG4CXX_EXPORT Logger
*/
void addErrorEvent(std::string&& message, const
spi::LocationInfo& location = spi::LocationInfo::getLocationUnavailable())
const;
+ /**
+ Add to attached appender(s) a new ERROR level LoggingEvent
which was requested at \c sourceLocation where the message is built
asynchronously by \c messageAppender
+ without further checks.
+ @param message The text to add to the logging event.
+ @param location The source code location of the logging request.
+ */
+ void addErrorEvent(helpers::AsyncBuffer&& messageAppender,
const spi::LocationInfo& location =
spi::LocationInfo::getLocationUnavailable()) const;
+
/**
Add a new warning level logging event containing \c message and
\c location to attached appender(s)
without further checks.
@@ -530,6 +557,14 @@ class LOG4CXX_EXPORT Logger
*/
void addWarnEvent(std::string&& message, const
spi::LocationInfo& location = spi::LocationInfo::getLocationUnavailable())
const;
+ /**
+ Add to attached appender(s) a new WARN level LoggingEvent which
was requested at \c sourceLocation where the message is built asynchronously by
\c messageAppender
+ without further checks.
+ @param message The text to add to the logging event.
+ @param location The source code location of the logging request.
+ */
+ void addWarnEvent(helpers::AsyncBuffer&& messageAppender, const
spi::LocationInfo& location = spi::LocationInfo::getLocationUnavailable())
const;
+
/**
Add a new info level logging event containing \c message and \c
location to attached appender(s)
without further checks.
@@ -538,6 +573,14 @@ class LOG4CXX_EXPORT Logger
*/
void addInfoEvent(std::string&& message, const
spi::LocationInfo& location = spi::LocationInfo::getLocationUnavailable())
const;
+ /**
+ Add to attached appender(s) a new INFO level LoggingEvent which
was requested at \c sourceLocation where the message is built asynchronously by
\c messageAppender
+ without further checks.
+ @param message The text to add to the logging event.
+ @param location The source code location of the logging request.
+ */
+ void addInfoEvent(helpers::AsyncBuffer&& messageAppender, const
spi::LocationInfo& location = spi::LocationInfo::getLocationUnavailable())
const;
+
/**
Add a new debug level logging event containing \c message and
\c location to attached appender(s)
without further checks.
@@ -546,6 +589,14 @@ class LOG4CXX_EXPORT Logger
*/
void addDebugEvent(std::string&& message, const
spi::LocationInfo& location = spi::LocationInfo::getLocationUnavailable())
const;
+ /**
+ Add to attached appender(s) a new DEBUG level LoggingEvent
which was requested at \c sourceLocation where the message is built
asynchronously by \c messageAppender
+ without further checks.
+ @param message The text to add to the logging event.
+ @param location The source code location of the logging request.
+ */
+ void addDebugEvent(helpers::AsyncBuffer&& messageAppender,
const spi::LocationInfo& location =
spi::LocationInfo::getLocationUnavailable()) const;
+
/**
Add a new trace level logging event containing \c message and
\c location to attached appender(s)
without further checks.
@@ -554,6 +605,14 @@ class LOG4CXX_EXPORT Logger
*/
void addTraceEvent(std::string&& message, const
spi::LocationInfo& location = spi::LocationInfo::getLocationUnavailable())
const;
+ /**
+ Add to attached appender(s) a new TRACE level LoggingEvent
which was requested at \c sourceLocation where the message is built
asynchronously by \c messageAppender
+ without further checks.
+ @param message The text to add to the logging event.
+ @param location The source code location of the logging request.
+ */
+ void addTraceEvent(helpers::AsyncBuffer&& messageAppender,
const spi::LocationInfo& location =
spi::LocationInfo::getLocationUnavailable()) const;
+
/**
Add a new logging event containing \c message and \c location
to attached appender(s)
without further checks.
diff --git a/src/main/include/log4cxx/spi/loggingevent.h
b/src/main/include/log4cxx/spi/loggingevent.h
index cd0b81c8..e40c8a5f 100644
--- a/src/main/include/log4cxx/spi/loggingevent.h
+++ b/src/main/include/log4cxx/spi/loggingevent.h
@@ -87,6 +87,21 @@ class LOG4CXX_EXPORT LoggingEvent :
, const LocationInfo& location
);
+ /**
+ An event composed using the supplied parameters.
+
+ @param logger The logger used to make the logging request.
+ @param level The severity of this event.
+ @param location The source code location of the logging request.
+ @param messageAppender Builds the message text to add to this
event.
+ */
+ LoggingEvent
+ ( const LogString& logger
+ , const LevelPtr& level
+ , const LocationInfo& location
+ , helpers::AsyncBuffer&& messageAppender
+ );
+
~LoggingEvent();
/** The severity level of the logging request that generated
this event. */
@@ -195,6 +210,11 @@ class LOG4CXX_EXPORT LoggingEvent :
*/
void setProperty(const LogString& key, const LogString& value);
+ /**
+ * Use the renderers to construct the message
+ */
+ void renderMessage();
+
private:
LOG4CXX_DECLARE_PRIVATE_MEMBER_PTR(LoggingEventPrivate, m_priv)
diff --git a/src/site/markdown/change-report-gh.md
b/src/site/markdown/change-report-gh.md
index 9d9d93c3..4b8b5354 100644
--- a/src/site/markdown/change-report-gh.md
+++ b/src/site/markdown/change-report-gh.md
@@ -61,6 +61,8 @@ and the LOG4CXX_CONFIGURATION environment variable (see
log4cxx::spi::Configurat
\[[#520](https://github.com/apache/logging-log4cxx/pull/520)\]
* Console output (Log4cxx internal logging and BasicConfigurator) use a color
per message level by default
\[[#529](https://github.com/apache/logging-log4cxx/pull/529)\]
+* New logging macros that defer binary-to-text conversion until used in
AsyncAppender's background thread
+ \[[#548](https://github.com/apache/logging-log4cxx/pull/548)\]
The following issues have been addressed:
diff --git a/src/site/markdown/performance.md b/src/site/markdown/performance.md
index 56723501..608e5cc7 100644
--- a/src/site/markdown/performance.md
+++ b/src/site/markdown/performance.md
@@ -98,8 +98,10 @@ The "Iterations" column derivation is explained in [Google
Benchmark documentati
| Appending int+float using FMT, pattern: \%m\%n/threads:6 | 537 ns | 3036 ns
| 212844 |
| Appending int+10float using FMT, pattern: \%m\%n | 1671 ns | 1671 ns |
417402 |
| Appending int+10float using FMT, pattern: \%m\%n/threads:6 | 1275 ns | 7297
ns | 96222 |
-| Async, Sending int+10float using FMT | 1663 ns | 1663 ns | 421796 |
-| Async, Sending int+10float using FMT/threads:6 | 1286 ns | 7368 ns | 88308 |
+| Async, Sending int+10float using FMT | 2190 ns | 2190 ns | 320109 |
+| Async, Sending int+10float using FMT/threads:6 | 1363 ns | 7862 ns | 84306 |
+| Async, Sending int+10float using AsyncBuffer, pattern: \%m\%n | 1226 ns |
1226 ns | 571351 |
+| Async, Sending int+10float using AsyncBuffer, pattern: \%m\%n/threads:6 |
1398 ns | 7902 ns | 89688 |
| Logging int+float using MessageBuffer, pattern: \%d \%m\%n | 1073 ns | 1073
ns | 656652 |
| Logging int+float using MessageBuffer, pattern: \%d \%m\%n/threads:6 | 1083
ns | 4895 ns | 142776 |
| Logging int+float using MessageBuffer, JSON | 1394 ns | 1394 ns | 507493 |
@@ -137,5 +139,6 @@ and the blocking transfer of message data to the operating
system
from the calling thread to the background thread.
When logging floating point values from a high priority thread,
+and you cannot use a background thread to format and write the log data,
the LOG4CXX_[level]_FMT series of macros impose the least overhead.
diff --git a/src/test/cpp/asyncappendertestcase.cpp
b/src/test/cpp/asyncappendertestcase.cpp
index 28b2c9e6..42a2eaae 100644
--- a/src/test/cpp/asyncappendertestcase.cpp
+++ b/src/test/cpp/asyncappendertestcase.cpp
@@ -104,13 +104,14 @@ class LoggingVectorAppender : public VectorAppender
LoggerInstancePtr logger{ "LoggingVectorAppender" };
void append(const spi::LoggingEventPtr& event, log4cxx::helpers::Pool&
p) override
{
+ auto lsMsg = event->getRenderedMessage();
VectorAppender::append(event, p);
- if (event->getMessage() == LOG4CXX_STR("Hello, World"))
+ if (LogString::npos != lsMsg.find(LOG4CXX_STR("World")))
{
- LOG4CXX_LOGLS(logger, Level::getError(),
LOG4CXX_STR("Some example error"));
- LOG4CXX_LOGLS(logger, Level::getWarn(),
LOG4CXX_STR("Some example warning"));
- LOG4CXX_LOGLS(logger, Level::getInfo(),
LOG4CXX_STR("Some information"));
- LOG4CXX_LOGLS(logger, Level::getDebug(),
LOG4CXX_STR("Some detailed data"));
+ LOG4CXX_LOGLS(logger, Level::getError(),
LOG4CXX_STR("Some appender error"));
+ LOG4CXX_LOGLS(logger, Level::getWarn(),
LOG4CXX_STR("Some appender warning"));
+ LOG4CXX_LOGLS(logger, Level::getInfo(),
LOG4CXX_STR("Some appender information"));
+ LOG4CXX_LOGLS(logger, Level::getDebug(),
LOG4CXX_STR("Some appender detailed data"));
}
}
};
@@ -129,6 +130,7 @@ class AsyncAppenderTestCase : public
AppenderSkeletonTestCase
LOGUNIT_TEST(closeTest);
LOGUNIT_TEST(test2);
+ LOGUNIT_TEST(testAutoMessageBufferSelection);
LOGUNIT_TEST(testEventFlush);
LOGUNIT_TEST(testMultiThread);
LOGUNIT_TEST(testBadAppender);
@@ -205,6 +207,37 @@ class AsyncAppenderTestCase : public
AppenderSkeletonTestCase
LOGUNIT_ASSERT(vectorAppender->isClosed());
}
+ // Test behaviour when logging with a char type that is not
logchar
+ void testAutoMessageBufferSelection()
+ {
+ VectorAppenderPtr vectorAppender;
+ auto r = LogManager::getLoggerRepository();
+ r->ensureIsConfigured([r, &vectorAppender]()
+ {
+ vectorAppender =
std::make_shared<VectorAppender>();
+ r->getRootLogger()->addAppender(vectorAppender);
+ });
+ auto root = r->getRootLogger();
+
+ int expectedMessageCount = 1;
+#ifdef LOG4CXX_XXXX_ASYNC_MACROS_WORK_WITH_ANY_CHAR_TYPE
+ ++expectedMessageCount
+#if LOG4CXX_LOGCHAR_IS_UTF8
+ LOG4CXX_INFO_ASYNC(root, L"Some wide string " << 42);
+#else
+ LOG4CXX_INFO_ASYNC(root, "Some narrow string " << 42);
+#endif
+#endif // LOG4CXX_XXXX_ASYNC_MACROS_WORK_WITH_ANY_CHAR_TYPE
+
+#if LOG4CXX_LOGCHAR_IS_UTF8
+ LOG4CXX_INFO(root, L"Some wide string " << 42);
+#else
+ LOG4CXX_INFO(root, "Some narrow string " << 42);
+#endif
+ auto& v = vectorAppender->getVector();
+ LOGUNIT_ASSERT_EQUAL(expectedMessageCount,
int(v.size()));
+ }
+
// this test checks all messages are delivered when an
AsyncAppender is closed
void testEventFlush()
{
@@ -219,7 +252,7 @@ class AsyncAppenderTestCase : public
AppenderSkeletonTestCase
for (size_t i = 0; i < LEN; i++)
{
- LOG4CXX_DEBUG(root, "message" << i);
+ LOG4CXX_DEBUG_ASYNC(root, "message" << i);
}
asyncAppender->close();
@@ -232,7 +265,7 @@ class AsyncAppenderTestCase : public
AppenderSkeletonTestCase
{
LogString m(LOG4CXX_STR("message"));
StringHelper::toString(i, p, m);
- LOGUNIT_ASSERT(v[i]->getMessage() == m);
+ LOGUNIT_ASSERT(v[i]->getRenderedMessage() == m);
}
LOGUNIT_ASSERT_EQUAL(true, vectorAppender->isClosed());
}
@@ -257,7 +290,7 @@ class AsyncAppenderTestCase : public
AppenderSkeletonTestCase
{
for (int i = 0; i < LEN; i++)
{
- LOG4CXX_DEBUG(root, "message"
<< i);
+ LOG4CXX_DEBUG_ASYNC(root,
"message" << i);
}
});
}
@@ -277,7 +310,7 @@ class AsyncAppenderTestCase : public
AppenderSkeletonTestCase
std::vector<int> msgCount(LEN, 0);
for (auto m : v)
{
- auto i =
StringHelper::toInt(m->getMessage().substr(7));
+ auto i =
StringHelper::toInt(m->getRenderedMessage().substr(7));
LOGUNIT_ASSERT(0 <= i);
LOGUNIT_ASSERT(i < LEN);
++msgCount[i];
@@ -340,17 +373,17 @@ class AsyncAppenderTestCase : public
AppenderSkeletonTestCase
async->activateOptions(p);
auto rootLogger = Logger::getRootLogger();
rootLogger->addAppender(async);
- LOG4CXX_INFO(rootLogger, "Hello, World"); // This
causes the dispatch thread creation
+ LOG4CXX_INFO_ASYNC(rootLogger, "Hello, World"); // This
causes the dispatch thread creation
std::this_thread::sleep_for( std::chrono::milliseconds(
10 ) ); // Wait for the dispatch thread to be ready
{
std::lock_guard<std::mutex>
sync(blockableAppender->getBlocker());
for (int i = 0; i < 140; i++)
{
- LOG4CXX_INFO(rootLogger, "Hello,
World");
+ LOG4CXX_INFO_ASYNC(rootLogger, "Hello,
World " << i);
}
- LOG4CXX_ERROR(rootLogger, "That's all folks.");
+ LOG4CXX_ERROR_ASYNC(rootLogger, "That's all
folks.");
}
async->close();
@@ -359,14 +392,14 @@ class AsyncAppenderTestCase : public
AppenderSkeletonTestCase
LOGUNIT_ASSERT(!events.empty());
LOGUNIT_ASSERT(events.size() <= 142);
LoggingEventPtr initialEvent = events.front();
- LOGUNIT_ASSERT(initialEvent->getMessage() ==
LOG4CXX_STR("Hello, World"));
+ LOGUNIT_ASSERT(initialEvent->getRenderedMessage() ==
LOG4CXX_STR("Hello, World"));
std::map<LevelPtr, int> levelCount;
int discardMessageCount{ 0 };
LoggingEventPtr discardEvent;
for (auto& e : events)
{
++levelCount[e->getLevel()];
- if (e->getMessage().substr(0, 10) ==
LOG4CXX_STR("Discarded "))
+ if (e->getRenderedMessage().substr(0, 10) ==
LOG4CXX_STR("Discarded "))
{
++discardMessageCount;
discardEvent = e;
@@ -414,45 +447,46 @@ class AsyncAppenderTestCase : public
AppenderSkeletonTestCase
async->activateOptions(p);
auto rootLogger = Logger::getRootLogger();
rootLogger->addAppender(async);
- LOG4CXX_INFO(rootLogger, "Hello, World"); // This
causes the dispatch thread creation
+ LOG4CXX_INFO_ASYNC(rootLogger, "Hello, World"); // This
causes the dispatch thread creation
std::this_thread::sleep_for( std::chrono::milliseconds(
10 ) ); // Wait for the dispatch thread to be ready
for (int i = 0; i < 10; i++)
{
- LOG4CXX_INFO(rootLogger, "Hello, World");
+ LOG4CXX_INFO_ASYNC(rootLogger, "Hello, World "
<< i);
}
- LOG4CXX_INFO(rootLogger, "Bye bye World");
+ LOG4CXX_INFO_ASYNC(rootLogger, "Bye bye World");
std::this_thread::sleep_for( std::chrono::milliseconds(
10 ) ); // Wait for the dispatch thread take the above events
async->close();
auto& events = loggingAppender->getVector();
std::map<LevelPtr, int> levelCount;
int discardMessageCount{ 0 };
+ int eventCount[] = { 0, 0 };
for (auto& e : events)
{
++levelCount[e->getLevel()];
- auto message = e->getMessage();
+ auto message = e->getRenderedMessage();
+ LogLog::debug(message);
+ auto isAppenderMessage = (message.npos ==
message.find(LOG4CXX_STR("World")));
+ ++eventCount[isAppenderMessage];
if (message.substr(0, 10) ==
LOG4CXX_STR("Discarded "))
{
++discardMessageCount;
- auto isAppenderMessage = (message.npos
== message.find(LOG4CXX_STR("World")));
LOGUNIT_ASSERT(isAppenderMessage);
}
}
if (helpers::LogLog::isDebugEnabled())
{
LogString msg{ LOG4CXX_STR("messageCounts:") };
- for (auto& item : levelCount)
- {
- msg += LOG4CXX_STR(" ");
- msg += item.first->toString();
- msg += LOG4CXX_STR(" ");
- StringHelper::toString(item.second, p,
msg);
- }
- msg += LOG4CXX_STR(" ");
- msg += LOG4CXX_STR("Discarded ");
+ msg += LOG4CXX_STR(" nonAppender ");
+ StringHelper::toString(eventCount[0], p, msg);
+ msg += LOG4CXX_STR(" appender ");
+ StringHelper::toString(eventCount[1], p, msg);
+ msg += LOG4CXX_STR(" discard ");
StringHelper::toString(discardMessageCount, p,
msg);
- helpers::LogLog::debug(msg);
+ LogLog::debug(msg);
}
LOGUNIT_ASSERT(12 < events.size());
+ // A race condition in AsyncAppender can result in a
lost message when the dispatch thread is logging events
+ LOGUNIT_ASSERT(10 <= eventCount[0]);
}
#if LOG4CXX_HAS_DOMCONFIGURATOR
@@ -479,7 +513,7 @@ class AsyncAppenderTestCase : public
AppenderSkeletonTestCase
for (size_t i = 0; i < LEN; i++)
{
- LOG4CXX_DEBUG(root, "message" << i);
+ LOG4CXX_DEBUG_ASYNC(root, "message" << i);
}
asyncAppender->close();
diff --git a/src/test/cpp/benchmark/benchmark.cpp
b/src/test/cpp/benchmark/benchmark.cpp
index ac792837..3de48d53 100644
--- a/src/test/cpp/benchmark/benchmark.cpp
+++ b/src/test/cpp/benchmark/benchmark.cpp
@@ -132,7 +132,7 @@ void disableThousandSeparatorsInJSON()
class benchmarker : public ::benchmark::Fixture
{
public: // Attributes
- LoggerPtr m_logger = getLogger();
+ LoggerPtr m_appender = getNullWriter();
LoggerPtr m_asyncLogger = getAsyncLogger();
LoggerPtr m_fileLogger = getFileLogger();
LoggerPtr m_JSONLogger = getJSONFileLogger();
@@ -176,7 +176,7 @@ public: // Class methods
});
}
- static LoggerPtr getLogger(const LogString& pattern = LogString())
+ static LoggerPtr getNullWriter(const LogString& pattern = LogString())
{
static struct initializer
{
@@ -303,10 +303,10 @@ public: // Class methods
BENCHMARK_DEFINE_F(benchmarker, logDisabledTrace)(benchmark::State& state)
{
- m_logger->setLevel(Level::getDebug());
+ m_appender->setLevel(Level::getDebug());
for (auto _ : state)
{
- LOG4CXX_TRACE( m_logger, LOG4CXX_STR("Hello: static string
message"));
+ LOG4CXX_TRACE( m_appender, LOG4CXX_STR("Hello: static string
message"));
}
}
BENCHMARK_REGISTER_F(benchmarker, logDisabledTrace)->Name("Testing disabled
logging request")->MinWarmUpTime(benchmarker::warmUpSeconds());
@@ -314,10 +314,10 @@ BENCHMARK_REGISTER_F(benchmarker,
logDisabledTrace)->Name("Testing disabled logg
BENCHMARK_DEFINE_F(benchmarker, logShortString)(benchmark::State& state)
{
- m_logger->setLevel(Level::getInfo());
+ m_appender->setLevel(Level::getInfo());
for (auto _ : state)
{
- LOG4CXX_INFO(m_logger, LOG4CXX_STR("Hello"));
+ LOG4CXX_INFO(m_appender, LOG4CXX_STR("Hello"));
}
}
BENCHMARK_REGISTER_F(benchmarker, logShortString)->Name("Appending 5 char
string using MessageBuffer, pattern: %m%n");
@@ -325,10 +325,10 @@ BENCHMARK_REGISTER_F(benchmarker,
logShortString)->Name("Appending 5 char string
BENCHMARK_DEFINE_F(benchmarker, logLongString)(benchmark::State& state)
{
- m_logger->setLevel(Level::getInfo());
+ m_appender->setLevel(Level::getInfo());
for (auto _ : state)
{
- LOG4CXX_INFO( m_logger, LOG4CXX_STR("Hello: this is a long
static string message"));
+ LOG4CXX_INFO( m_appender, LOG4CXX_STR("Hello: this is a long
static string message"));
}
}
BENCHMARK_REGISTER_F(benchmarker, logLongString)->Name("Appending 49 char
string using MessageBuffer, pattern: %m%n");
@@ -339,7 +339,7 @@ BENCHMARK_DEFINE_F(benchmarker,
logIntValueMessageBuffer)(benchmark::State& stat
int x = 0;
for (auto _ : state)
{
- LOG4CXX_INFO( m_logger, "Hello: message number " << ++x);
+ LOG4CXX_INFO( m_appender, "Hello: message number " << ++x);
}
}
BENCHMARK_REGISTER_F(benchmarker, logIntValueMessageBuffer)->Name("Appending
int value using MessageBuffer, pattern: %m%n");
@@ -351,7 +351,7 @@ BENCHMARK_DEFINE_F(benchmarker,
logIntPlusFloatMessageBuffer)(benchmark::State&
for (auto _ : state)
{
auto f = static_cast<float>(rand()) /
static_cast<float>(RAND_MAX);
- LOG4CXX_INFO( m_logger, "Hello: message number " << ++x
+ LOG4CXX_INFO( m_appender, "Hello: message number " << ++x
<< " pseudo-random float " << std::setprecision(3) <<
std::fixed << f);
}
}
@@ -398,7 +398,7 @@ void logWithConversionPattern(benchmark::State& state,
Args&&... args)
{
auto args_tuple = std::make_tuple(std::move(args)...);
LogString conversionPattern = std::get<0>(args_tuple);
- auto logger = benchmarker::getLogger(conversionPattern);
+ auto logger = benchmarker::getNullWriter(conversionPattern);
int x = 0;
for (auto _ : state)
{
@@ -413,7 +413,7 @@ BENCHMARK_DEFINE_F(benchmarker,
logLongStringFMT)(benchmark::State& state)
{
for (auto _ : state)
{
- LOG4CXX_INFO_FMT(m_logger, "Hello: this is a long static string
message", 0);
+ LOG4CXX_INFO_FMT(m_appender, "Hello: this is a long static
string message", 0);
}
}
BENCHMARK_REGISTER_F(benchmarker, logLongStringFMT)->Name("Appending 49 char
string using FMT, pattern: %m%n");
@@ -424,7 +424,7 @@ BENCHMARK_DEFINE_F(benchmarker,
logIntValueFMT)(benchmark::State& state)
int x = 0;
for (auto _ : state)
{
- LOG4CXX_INFO_FMT(m_logger, "Hello: msg number {}", ++x);
+ LOG4CXX_INFO_FMT(m_appender, "Hello: msg number {}", ++x);
}
}
BENCHMARK_REGISTER_F(benchmarker, logIntValueFMT)->Name("Appending int value
using FMT, pattern: %m%n");
@@ -436,7 +436,7 @@ BENCHMARK_DEFINE_F(benchmarker,
logIntPlusFloatValueFMT)(benchmark::State& state
for (auto _ : state)
{
auto f = static_cast<float>(rand()) /
static_cast<float>(RAND_MAX);
- LOG4CXX_INFO_FMT(m_logger, "Hello: msg number {} pseudo-random
float {:.3f}", ++x, f);
+ LOG4CXX_INFO_FMT(m_appender, "Hello: msg number {}
pseudo-random float {:.3f}", ++x, f);
}
}
BENCHMARK_REGISTER_F(benchmarker, logIntPlusFloatValueFMT)->Name("Appending
int+float using FMT, pattern: %m%n");
@@ -459,7 +459,7 @@ BENCHMARK_DEFINE_F(benchmarker,
logIntPlus10FloatValueFMT)(benchmark::State& sta
, static_cast<float>(rand()) / static_cast<float>(RAND_MAX)
, static_cast<float>(rand()) / static_cast<float>(RAND_MAX)
};
- LOG4CXX_INFO_FMT(m_logger, "Hello: msg number {} pseudo-random
float {:.3f} {:.3f} {:.3f} {:.3f} {:.3f} {:.3f} {:.3f} {:.3f} {:.3f} {:.3f}"
+ LOG4CXX_INFO_FMT(m_appender, "Hello: msg number {}
pseudo-random float {:.3f} {:.3f} {:.3f} {:.3f} {:.3f} {:.3f} {:.3f} {:.3f}
{:.3f} {:.3f}"
, ++x
, f[0]
, f[1]
@@ -476,7 +476,6 @@ BENCHMARK_DEFINE_F(benchmarker,
logIntPlus10FloatValueFMT)(benchmark::State& sta
}
BENCHMARK_REGISTER_F(benchmarker, logIntPlus10FloatValueFMT)->Name("Appending
int+10float using FMT, pattern: %m%n");
BENCHMARK_REGISTER_F(benchmarker, logIntPlus10FloatValueFMT)->Name("Appending
int+10float using FMT, pattern: %m%n")->Threads(benchmarker::threadCount());
-#endif
BENCHMARK_DEFINE_F(benchmarker,
asyncIntPlus10FloatValueFmtBuffer)(benchmark::State& state)
{
@@ -495,7 +494,7 @@ BENCHMARK_DEFINE_F(benchmarker,
asyncIntPlus10FloatValueFmtBuffer)(benchmark::St
, static_cast<float>(rand()) / static_cast<float>(RAND_MAX)
, static_cast<float>(rand()) / static_cast<float>(RAND_MAX)
};
- LOG4CXX_INFO_FMT(m_logger, "Hello: msg number {} pseudo-random
float {:.3f} {:.3f} {:.3f} {:.3f} {:.3f} {:.3f} {:.3f} {:.3f} {:.3f} {:.3f}"
+ LOG4CXX_INFO_FMT(m_asyncLogger, "Hello: msg number {}
pseudo-random float {:.3f} {:.3f} {:.3f} {:.3f} {:.3f} {:.3f} {:.3f} {:.3f}
{:.3f} {:.3f}"
, ++x
, f[0]
, f[1]
@@ -512,6 +511,42 @@ BENCHMARK_DEFINE_F(benchmarker,
asyncIntPlus10FloatValueFmtBuffer)(benchmark::St
}
BENCHMARK_REGISTER_F(benchmarker,
asyncIntPlus10FloatValueFmtBuffer)->Name("Async, Sending int+10float using
FMT");
BENCHMARK_REGISTER_F(benchmarker,
asyncIntPlus10FloatValueFmtBuffer)->Name("Async, Sending int+10float using
FMT")->Threads(benchmarker::threadCount());
+#endif
+
+BENCHMARK_DEFINE_F(benchmarker,
asyncIntPlus10FloatAsyncBuffer)(benchmark::State& state)
+{
+ int x = 0;
+ for (auto _ : state)
+ {
+ float f[] =
+ { static_cast<float>(rand()) / static_cast<float>(RAND_MAX)
+ , static_cast<float>(rand()) / static_cast<float>(RAND_MAX)
+ , static_cast<float>(rand()) / static_cast<float>(RAND_MAX)
+ , static_cast<float>(rand()) / static_cast<float>(RAND_MAX)
+ , static_cast<float>(rand()) / static_cast<float>(RAND_MAX)
+ , static_cast<float>(rand()) / static_cast<float>(RAND_MAX)
+ , static_cast<float>(rand()) / static_cast<float>(RAND_MAX)
+ , static_cast<float>(rand()) / static_cast<float>(RAND_MAX)
+ , static_cast<float>(rand()) / static_cast<float>(RAND_MAX)
+ , static_cast<float>(rand()) / static_cast<float>(RAND_MAX)
+ };
+ LOG4CXX_INFO_ASYNC(m_asyncLogger, "Hello: message number " <<
++x
+ << " pseudo-random float" << std::setprecision(3) <<
std::fixed
+ << ' ' << f[0]
+ << ' ' << f[1]
+ << ' ' << f[2]
+ << ' ' << f[3]
+ << ' ' << f[4]
+ << ' ' << f[5]
+ << ' ' << f[6]
+ << ' ' << f[7]
+ << ' ' << f[8]
+ << ' ' << f[9]
+ );
+ }
+}
+BENCHMARK_REGISTER_F(benchmarker,
asyncIntPlus10FloatAsyncBuffer)->Name("Async, Sending int+10float using
AsyncBuffer, pattern: %m%n");
+BENCHMARK_REGISTER_F(benchmarker,
asyncIntPlus10FloatAsyncBuffer)->Name("Async, Sending int+10float using
AsyncBuffer, pattern: %m%n")->Threads(benchmarker::threadCount());
BENCHMARK_DEFINE_F(benchmarker,
fileIntPlusFloatValueMessageBuffer)(benchmark::State& state)
{
