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 397c7824 Ensure all buffered log message are written at exit (#560)
397c7824 is described below
commit 397c78245b7caf3e194b3fd3e052f91168d0a74d
Author: Stephen Webb <[email protected]>
AuthorDate: Mon Nov 3 13:47:41 2025 +1100
Ensure all buffered log message are written at exit (#560)
* Add FAQ answer for why buffered asynchronous output is not the default
---
src/site/markdown/faq.md | 12 ++++
src/test/cpp/fileappendertest.cpp | 141 ++++++++++++++++++++++++++++++++++++--
2 files changed, 149 insertions(+), 4 deletions(-)
diff --git a/src/site/markdown/faq.md b/src/site/markdown/faq.md
index 62082561..20f54431 100644
--- a/src/site/markdown/faq.md
+++ b/src/site/markdown/faq.md
@@ -22,6 +22,18 @@ Frequently Asked Technical Questions {#faq}
-->
[TOC]
+## Why doesn't Log4cxx use buffered asynchronous output by
default?{#buffered_output}
+
+Being able to examine logged values is critically important during application
development.
+Buffering output prevents the log file from containing the lastest messages in
two situations:
+-# when a debugger stops the application at a break point
+-# when the application aborts abnormally
+(e.g. calls
[std::terminate](https://en.cppreference.com/w/cpp/error/terminate.html)
+or the operating system detects a fault)
+
+Debugging a program becomes extremely confusing when the log file
+does not contain the most recently written logging requests.
+
## How do I add a custom level to Apache Log4cxx?{#custom_levels}
This is a common topic for all the Apache logging frameworks and typically
motivated to try to
diff --git a/src/test/cpp/fileappendertest.cpp
b/src/test/cpp/fileappendertest.cpp
index 68e89b41..860a5f89 100644
--- a/src/test/cpp/fileappendertest.cpp
+++ b/src/test/cpp/fileappendertest.cpp
@@ -15,19 +15,24 @@
* limitations under the License.
*/
#include <log4cxx/basicconfigurator.h>
-#include <log4cxx/fileappender.h>
#include <log4cxx/logmanager.h>
#include <log4cxx/patternlayout.h>
#include <log4cxx/helpers/pool.h>
#include <log4cxx/helpers/loglog.h>
#include <log4cxx/helpers/stringhelper.h>
+#include <log4cxx/helpers/transcoder.h>
+#include <log4cxx/helpers/fileoutputstream.h>
+#include <log4cxx/rolling/rollingfileappender.h>
+#include <log4cxx/rolling/timebasedrollingpolicy.h>
#include "logunit.h"
#include <apr_time.h>
+#include <apr_thread_proc.h>
+#include <fstream>
using namespace log4cxx;
using namespace log4cxx::helpers;
-auto getLogger(const std::string& name = std::string()) -> LoggerPtr {
+auto getLogger(const LogString& name = {}) -> LoggerPtr {
static struct log4cxx_initializer {
log4cxx_initializer() {
auto layout =
std::make_shared<PatternLayout>(LOG4CXX_STR("%d %m%n"));
@@ -59,7 +64,9 @@ LOGUNIT_CLASS(FileAppenderTest)
LOGUNIT_TEST(testDirectoryCreation);
LOGUNIT_TEST(testgetSetThreshold);
LOGUNIT_TEST(testIsAsSevereAsThreshold);
- LOGUNIT_TEST(testBufferedOutput);
+ LOGUNIT_TEST(testPeriodicFlush);
+ LOGUNIT_TEST(writeFinalBufferOutput);
+ LOGUNIT_TEST(checkFinalBufferOutput);
LOGUNIT_TEST_SUITE_END();
#ifdef _DEBUG
@@ -119,7 +126,8 @@ public:
LOGUNIT_ASSERT(appender->isAsSevereAsThreshold(debug));
}
- void testBufferedOutput()
+ // Check a file is periodically flushed
+ void testPeriodicFlush()
{
auto logger = getLogger();
int requiredMsgCount = 10000;
@@ -136,6 +144,8 @@ public:
// wait 1.2 sec and check the buffer is flushed
apr_sleep(1200000);
size_t flushedLength = file.length(p);
+
+ // Check the file extended
if (helpers::LogLog::isDebugEnabled())
{
LogString msg(LOG4CXX_STR("initialLength "));
@@ -146,6 +156,129 @@ public:
}
LOGUNIT_ASSERT(initialLength < flushedLength);
}
+
+ // Used to check the buffer is flushed at exit
+ void writeFinalBufferOutput()
+ {
+ int requiredMsgCount = 100;
+ auto logger = getLogger(LOG4CXX_STR("100message"));
+
+ // Set up a new file
+ LogString dir{ LOG4CXX_STR("output/newdir") };
+ auto writer = std::make_shared<rolling::RollingFileAppender>();
+
writer->setLayout(std::make_shared<PatternLayout>(LOG4CXX_STR("%d %m%n")));
+ writer->setFile(dir + LOG4CXX_STR("/100message.log"));
+ writer->setBufferedIO(true);
+ writer->setBufferedSeconds(1);
+ auto policy =
std::make_shared<rolling::TimeBasedRollingPolicy>();
+ policy->setFileNamePattern(dir +
LOG4CXX_STR("/100message-%d{yyyy}.log"));
+ writer->setRollingPolicy(policy);
+ helpers::Pool p;
+ writer->activateOptions(p);
+ logger->setAdditivity(false);
+ logger->addAppender(writer);
+
+ for ( int x = 0; x < requiredMsgCount; x++ )
+ {
+ LOG4CXX_INFO( logger, "This is test message " << x );
+ }
+ }
+
+ void checkFinalBufferOutput()
+ {
+ helpers::Pool p;
+ // start a separate instance of this to write messages to the
file
+ helpers::FileOutputStream
output(LOG4CXX_STR("output/newdir/100message-writer.out"), false);
+ auto thisProgram = GetExecutableFileName();
+ const char* args[] = {thisProgram.c_str(),
"writeFinalBufferOutput", 0};
+ apr_procattr_t* attr = NULL;
+ setTestAttributes(&attr, output.getFilePtr(), p);
+ apr_proc_t pid;
+ startTestInstance(&pid, attr, args, p);
+
+ int exitCode;
+ apr_exit_why_e reason;
+ apr_proc_wait(&pid, &exitCode, &reason, APR_WAIT);
+ if (exitCode != 0)
+ {
+ LogString msg = LOG4CXX_STR("child exit code: ");
+ helpers::StringHelper::toString(exitCode, p, msg);
+ msg += LOG4CXX_STR("; reason: ");
+ helpers::StringHelper::toString(reason, p, msg);
+ helpers::LogLog::warn(msg);
+ }
+ LOGUNIT_ASSERT_EQUAL(exitCode, 0);
+
+ // Check all required messages are in the file
+ std::ifstream input("output/newdir/100message.log");
+ std::vector<int> messageCount;
+ int lineCount{ 0 };
+ for (std::string line; std::getline(input, line);)
+ {
+ ++lineCount;
+ auto pos = line.rfind(' ');
+ if (line.npos != pos && pos + 1 < line.size())
+ {
+ try
+ {
+ auto msgNumber =
std::stoull(line.substr(pos));
+ if (messageCount.size() <= msgNumber)
+ messageCount.resize(msgNumber +
1);
+ ++messageCount[msgNumber];
+ }
+ catch (std::exception const& ex)
+ {
+ LogString msg;
+ helpers::Transcoder::decode(ex.what(),
msg);
+ msg += LOG4CXX_STR(" processing\n");
+ helpers::Transcoder::decode(line, msg);
+ helpers::LogLog::warn(msg);
+ }
+ }
+ }
+ LogString msg = LOG4CXX_STR("lineCount: ");
+ helpers::StringHelper::toString(lineCount, p, msg);
+ helpers::LogLog::debug(msg);
+ for (auto& count : messageCount)
+ LOGUNIT_ASSERT_EQUAL(count, messageCount.front());
+ }
+
+private:
+
+ void setTestAttributes(apr_procattr_t** attr, apr_file_t* output,
helpers::Pool& p)
+ {
+ if (apr_procattr_create(attr, p.getAPRPool()) != APR_SUCCESS)
+ {
+ LOGUNIT_FAIL("apr_procattr_create");
+ }
+ if (apr_procattr_cmdtype_set(*attr, APR_PROGRAM) != APR_SUCCESS)
+ {
+ LOGUNIT_FAIL("apr_procattr_cmdtype_set");
+ }
+ if (apr_procattr_child_out_set(*attr, output, NULL) !=
APR_SUCCESS)
+ {
+ LOGUNIT_FAIL("apr_procattr_child_out_set");
+ }
+ if (apr_procattr_child_err_set(*attr, output, NULL) !=
APR_SUCCESS)
+ {
+ LOGUNIT_FAIL("apr_procattr_child_err_set");
+ }
+ }
+
+ void startTestInstance(apr_proc_t* pid, apr_procattr_t* attr, const
char** argv, helpers::Pool& p)
+ {
+ if (apr_proc_create(pid, argv[0], argv, NULL, attr,
p.getAPRPool()) != APR_SUCCESS)
+ {
+ LOGUNIT_FAIL("apr_proc_create");
+ }
+ }
+
+ std::string GetExecutableFileName()
+ {
+ auto lsProgramFilePath =
spi::Configurator::properties().getProperty(LOG4CXX_STR("PROGRAM_FILE_PATH"));
+ LOG4CXX_ENCODE_CHAR(programFilePath, lsProgramFilePath);
+ return programFilePath;
+ }
};
LOGUNIT_TEST_SUITE_REGISTRATION(FileAppenderTest);
