You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@logging.apache.org by sw...@apache.org on 2024/12/18 04:16:25 UTC
(logging-log4cxx) 01/01: Log elapsed time for multiprocessrollingappender unit test
This is an automated email from the ASF dual-hosted git repository.
swebb2066 pushed a commit to branch testing_multiprocessrollingappender
in repository https://gitbox.apache.org/repos/asf/logging-log4cxx.git
commit 5c66143e8be1f04d5e5fffdd86d156c7d8459a6f
Author: Stephen Webb <sw...@gmail.com>
AuthorDate: Wed Dec 18 15:15:54 2024 +1100
Log elapsed time for multiprocessrollingappender unit test
---
src/main/cpp/multiprocessrollingfileappender.cpp | 12 +++++++-
src/main/cpp/timebasedrollingpolicy.cpp | 19 ++++++++++++
.../log4cxx/rolling/timebasedrollingpolicy.h | 5 +++
src/test/cpp/rolling/multiprocessrollingtest.cpp | 36 ++++++++++++++++------
4 files changed, 62 insertions(+), 10 deletions(-)
diff --git a/src/main/cpp/multiprocessrollingfileappender.cpp b/src/main/cpp/multiprocessrollingfileappender.cpp
index 1c8d5651..86bb37c4 100644
--- a/src/main/cpp/multiprocessrollingfileappender.cpp
+++ b/src/main/cpp/multiprocessrollingfileappender.cpp
@@ -37,6 +37,12 @@
#include <mutex>
#include <thread>
+#ifdef WIN32 // apr_stat is slow on Windows
+#define USING_ROLLOVER_REQUIRED_CHECK_IS_FASTER 1
+#else
+#define USING_ROLLOVER_REQUIRED_CHECK_IS_FASTER 0
+#endif
+
using namespace LOG4CXX_NS;
using namespace LOG4CXX_NS::rolling;
using namespace LOG4CXX_NS::helpers;
@@ -158,7 +164,7 @@ void MultiprocessRollingFileAppender::activateOptions(Pool& p)
bool MultiprocessRollingFileAppender::isRolloverCheckNeeded()
{
bool result = true;
-#ifdef WIN32 // apr_stat is slow on Windows
+#if USING_ROLLOVER_REQUIRED_CHECK_IS_FASTER
if (auto pTimeBased = LOG4CXX_NS::cast<TimeBasedRollingPolicy>(_priv->rollingPolicy))
result = !pTimeBased->isLastFileNameUnchanged();
#endif
@@ -367,6 +373,10 @@ bool MultiprocessRollingFileAppender::synchronizedRollover(Pool& p, const Trigge
void MultiprocessRollingFileAppender::reopenFile(const LogString& fileName)
{
closeWriter();
+#if USING_ROLLOVER_REQUIRED_CHECK_IS_FASTER
+ if (auto pTimeBased = LOG4CXX_NS::cast<TimeBasedRollingPolicy>(_priv->rollingPolicy))
+ pTimeBased->loadLastFileName();
+#endif
OutputStreamPtr os = std::make_shared<FileOutputStream>(fileName, true);
WriterPtr newWriter(createWriter(os));
setFile(fileName);
diff --git a/src/main/cpp/timebasedrollingpolicy.cpp b/src/main/cpp/timebasedrollingpolicy.cpp
index 04c6ae52..bb1d7ba1 100644
--- a/src/main/cpp/timebasedrollingpolicy.cpp
+++ b/src/main/cpp/timebasedrollingpolicy.cpp
@@ -550,3 +550,22 @@ bool TimeBasedRollingPolicy::isLastFileNameUnchanged()
}
return result;
}
+
+/**
+ * Load the name (set by some other process) from shared memory
+ */
+void TimeBasedRollingPolicy::loadLastFileName()
+{
+ if( m_priv->multiprocess ){
+#if LOG4CXX_HAS_MULTIPROCESS_ROLLING_FILE_APPENDER
+ if (m_priv->_mmap)
+ {
+ lockMMapFile(APR_FLOCK_SHARED);
+ LogString mapLastFile((char*)m_priv->_mmap->mm);
+ unLockMMapFile();
+ if (!mapLastFile.empty())
+ m_priv->lastFileName = mapLastFile;
+ }
+#endif
+ }
+}
diff --git a/src/main/include/log4cxx/rolling/timebasedrollingpolicy.h b/src/main/include/log4cxx/rolling/timebasedrollingpolicy.h
index 696f53b2..8d4628c0 100755
--- a/src/main/include/log4cxx/rolling/timebasedrollingpolicy.h
+++ b/src/main/include/log4cxx/rolling/timebasedrollingpolicy.h
@@ -214,6 +214,11 @@ class LOG4CXX_EXPORT TimeBasedRollingPolicy : public virtual RollingPolicyBase,
*/
bool isLastFileNameUnchanged();
+ /**
+ * Load the name (set by some other process) from shared memory
+ */
+ void loadLastFileName();
+
protected:
/**
* A map from "d" and "date" to a date conversion formatter.
diff --git a/src/test/cpp/rolling/multiprocessrollingtest.cpp b/src/test/cpp/rolling/multiprocessrollingtest.cpp
index 4a57d0b8..7b12dba2 100644
--- a/src/test/cpp/rolling/multiprocessrollingtest.cpp
+++ b/src/test/cpp/rolling/multiprocessrollingtest.cpp
@@ -24,6 +24,7 @@
#include <log4cxx/rolling/sizebasedtriggeringpolicy.h>
#include <log4cxx/helpers/strftimedateformat.h>
#include <log4cxx/helpers/date.h>
+#include <log4cxx/helpers/fileoutputstream.h>
#include <log4cxx/helpers/loglog.h>
#include <log4cxx/helpers/stringhelper.h>
#include <filesystem>
@@ -109,7 +110,10 @@ public:
{
std::string expectedPrefix = LOG4CXX_STR("multiprocess-2-");
// remove any previously generated files
- for (auto const& dir_entry : std::filesystem::directory_iterator{"output/rolling"})
+ std::filesystem::path outputDir("output/rolling");
+ if (!exists(outputDir))
+ ;
+ else for (auto const& dir_entry : std::filesystem::directory_iterator{outputDir})
{
std::string filename(dir_entry.path().filename().string());
if (expectedPrefix.size() < filename.size() &&
@@ -183,12 +187,14 @@ public:
filename.substr(0, expectedPrefix.size()) == expectedPrefix)
std::filesystem::remove(dir_entry);
}
+ helpers::FileOutputStream output(LOG4CXX_STR("output/rolling/multiprocess-test4-child.log"), false);
auto thisProgram = GetExecutableFileName();
const char* args[] = {thisProgram.c_str(), "test3", 0};
helpers::Pool p;
apr_procattr_t* attr = NULL;
- setTestAttributes(&attr, p);
+ setTestAttributes(&attr, output.getFilePtr(), p);
apr_proc_t pid[5];
+ auto startTime = helpers::Date::currentTime();
for (auto i : {0, 1, 2, 3, 4})
startTestInstance(&pid[i], attr, args, p);
for (auto i : {0, 1, 2, 3, 4})
@@ -198,6 +204,14 @@ public:
apr_proc_wait(&pid[i], &exitCode, &reason, APR_WAIT);
LOGUNIT_ASSERT_EQUAL(exitCode, 0);
}
+ if (helpers::LogLog::isDebugEnabled())
+ {
+ LogString msg;
+ auto currentTime = helpers::Date::currentTime();
+ msg += LOG4CXX_STR("elapsed ");
+ helpers::StringHelper::toString(currentTime - startTime, p, msg);
+ helpers::LogLog::debug(msg);
+ }
// Check all messages are saved to files
std::string expectedSuffix(".log");
@@ -291,19 +305,23 @@ public:
private:
- void setTestAttributes(apr_procattr_t** attr, helpers::Pool& p)
+ 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 failed");
+ LOGUNIT_FAIL("apr_procattr_create");
+ }
+ if (apr_procattr_cmdtype_set(*attr, APR_PROGRAM) != APR_SUCCESS)
+ {
+ LOGUNIT_FAIL("apr_procattr_cmdtype_set");
}
- if (apr_procattr_io_set(*attr, APR_NO_PIPE, APR_NO_PIPE, APR_NO_PIPE) != APR_SUCCESS)
+ if (apr_procattr_child_out_set(*attr, output, NULL) != APR_SUCCESS)
{
- LOGUNIT_FAIL("apr_procattr_io_set failed");
+ LOGUNIT_FAIL("apr_procattr_child_out_set");
}
- if (apr_procattr_cmdtype_set(*attr, APR_PROGRAM) != APR_SUCCESS)
+ if (apr_procattr_child_err_set(*attr, output, NULL) != APR_SUCCESS)
{
- LOGUNIT_FAIL("apr_procattr_cmdtype_set failed");
+ LOGUNIT_FAIL("apr_procattr_child_err_set");
}
}
@@ -315,7 +333,7 @@ private:
}
else
{
- LOGUNIT_FAIL("apr_proc_create failed");
+ LOGUNIT_FAIL("apr_proc_create");
}
}