From 976955bf69d620983ba64e0bf90cb0214702d287 Mon Sep 17 00:00:00 2001 From: Stephen Webb Date: Sun, 22 Dec 2024 13:06:43 +1100 Subject: [PATCH] Periodically flush buffered file output (#445) * Document the new behavior of the BufferedIO option * Add unit test to ensure bufered output is asynchronously flushed * MSYS2 kills threads before all onexit functions complete so LogManager::shutdown is required on MSYS2 --- src/main/cpp/aprinitializer.cpp | 29 ++- src/main/cpp/fileappender.cpp | 39 +++- src/main/cpp/filewatchdog.cpp | 116 ++++----- src/main/cpp/logmanager.cpp | 2 + src/main/cpp/threadutility.cpp | 220 +++++++++++++++++- src/main/include/log4cxx/fileappender.h | 52 +++-- .../include/log4cxx/helpers/filewatchdog.h | 16 +- .../include/log4cxx/helpers/singletonholder.h | 52 +++++ .../include/log4cxx/helpers/threadutility.h | 40 +++- .../log4cxx/private/fileappender_priv.h | 13 ++ .../log4cxx/private/writerappender_priv.h | 10 +- src/test/cpp/fileappendertest.cpp | 43 ++++ 12 files changed, 514 insertions(+), 118 deletions(-) create mode 100644 src/main/include/log4cxx/helpers/singletonholder.h diff --git a/src/main/cpp/aprinitializer.cpp b/src/main/cpp/aprinitializer.cpp index 454b77184..a4346e721 100644 --- a/src/main/cpp/aprinitializer.cpp +++ b/src/main/cpp/aprinitializer.cpp @@ -34,6 +34,8 @@ using namespace LOG4CXX_NS; bool APRInitializer::isDestructed = false; +using IdentifiedObject = std::pair; + struct APRInitializer::APRInitializerPrivate{ APRInitializerPrivate() : p(0), @@ -41,13 +43,19 @@ struct APRInitializer::APRInitializerPrivate{ tlsKey(0){ } + ~APRInitializerPrivate() + { + // Delete in reverse order + while (!objects.empty()) + objects.pop_back(); + } apr_pool_t* p; std::mutex mutex; std::list watchdogs; log4cxx_time_t startTime; apr_threadkey_t* tlsKey; - std::map objects; + std::vector objects; }; namespace @@ -171,7 +179,13 @@ void APRInitializer::unregisterCleanup(FileWatchdog* watchdog) void APRInitializer::addObject(size_t key, const ObjectPtr& pObject) { std::lock_guard lock(m_priv->mutex); - m_priv->objects[key] = pObject; + auto pItem = std::find_if(m_priv->objects.begin(), m_priv->objects.end() + , [key](const IdentifiedObject& item) { return item.first == key; } + ); + if (m_priv->objects.end() != pItem) + pItem->second = pObject; + else + m_priv->objects.emplace_back(key, pObject); } const ObjectPtr& APRInitializer::findOrAddObject(size_t key, std::function creator) @@ -182,8 +196,11 @@ const ObjectPtr& APRInitializer::findOrAddObject(size_t key, std::functionobjects.find(key); - if (m_priv->objects.end() == pItem) - pItem = m_priv->objects.emplace(key, creator()).first; - return pItem->second; + auto pItem = std::find_if(m_priv->objects.begin(), m_priv->objects.end() + , [key](const IdentifiedObject& item) { return item.first == key; } + ); + if (m_priv->objects.end() != pItem) + return pItem->second; + m_priv->objects.emplace_back(key, creator()); + return m_priv->objects.back().second; } diff --git a/src/main/cpp/fileappender.cpp b/src/main/cpp/fileappender.cpp index da5360741..d8a55aca0 100644 --- a/src/main/cpp/fileappender.cpp +++ b/src/main/cpp/fileappender.cpp @@ -25,6 +25,7 @@ #include #include #include +#include "log4cxx/helpers/threadutility.h" #include #include #include @@ -81,6 +82,8 @@ FileAppender::FileAppender(std::unique_ptr priv) FileAppender::~FileAppender() { finalize(); + if (auto p = _priv->taskManager.lock()) + p->value().removePeriodicTask(getName()); } void FileAppender::setAppend(bool fileAppend1) @@ -140,6 +143,11 @@ void FileAppender::setOption(const LogString& option, std::lock_guard lock(_priv->mutex); _priv->bufferSize = OptionConverter::toFileSize(value, 8 * 1024); } + else if (StringHelper::equalsIgnoreCase(option, LOG4CXX_STR("BUFFEREDSECONDS"), LOG4CXX_STR("bufferedseconds"))) + { + std::lock_guard lock(_priv->mutex); + _priv->bufferedSeconds = OptionConverter::toInt(value, 0); + } else { WriterAppender::setOption(option, value); @@ -184,6 +192,23 @@ void FileAppender::activateOptionsInternal(Pool& p) if (errors == 0) { WriterAppender::activateOptions(p); + + if (!_priv->bufferedIO) + ; + else if (0 < _priv->bufferedSeconds) + { + auto taskManager = ThreadUtility::instancePtr(); + taskManager->value().addPeriodicTask(getName() + , std::bind(&WriterAppenderPriv::flush, _priv) + , std::chrono::seconds(_priv->bufferedSeconds) + ); + _priv->taskManager = taskManager; + } + else if (0 == _priv->bufferedSeconds) + { + if (auto p = _priv->taskManager.lock()) + p->value().removePeriodicTask(getName()); + } } } @@ -370,9 +395,19 @@ int FileAppender::getBufferSize() const return _priv->bufferSize; } -void FileAppender::setBufferSize(int bufferSize1) +int FileAppender::getBufferedSeconds() const +{ + return _priv->bufferedSeconds; +} + +void FileAppender::setBufferSize(int newValue) +{ + _priv->bufferSize = newValue; +} + +void FileAppender::setBufferedSeconds(int newValue) { - _priv->bufferSize = bufferSize1; + _priv->bufferedSeconds = newValue; } bool FileAppender::getAppend() const diff --git a/src/main/cpp/filewatchdog.cpp b/src/main/cpp/filewatchdog.cpp index 903d93080..e7101bd47 100644 --- a/src/main/cpp/filewatchdog.cpp +++ b/src/main/cpp/filewatchdog.cpp @@ -24,10 +24,8 @@ #include #include #include - -#if LOG4CXX_EVENTS_AT_EXIT -#include -#endif +#include +#include using namespace LOG4CXX_NS; using namespace LOG4CXX_NS::helpers; @@ -37,14 +35,10 @@ long FileWatchdog::DEFAULT_DELAY = 60000; struct FileWatchdog::FileWatchdogPrivate{ FileWatchdogPrivate(const File& file1) : file(file1), delay(DEFAULT_DELAY), lastModif(0), - warnedAlready(false), interrupted(0), thread() -#if LOG4CXX_EVENTS_AT_EXIT - , atExitRegistryRaii([this]{stopWatcher();}) -#endif + warnedAlready(false), + taskName{ LOG4CXX_STR("WatchDog_") + file1.getName() } { } - ~FileWatchdogPrivate() - { stopWatcher(); } /** The name of the file to observe for changes. @@ -57,26 +51,15 @@ struct FileWatchdog::FileWatchdogPrivate{ long delay; log4cxx_time_t lastModif; bool warnedAlready; - volatile int interrupted; +#if LOG4CXX_ABI_VERSION <= 15 + int interrupted{ 0 }; Pool pool; std::thread thread; std::condition_variable interrupt; std::mutex interrupt_mutex; - -#if LOG4CXX_EVENTS_AT_EXIT - helpers::AtExitRegistry::Raii atExitRegistryRaii; #endif - - void stopWatcher() - { - { - std::lock_guard lock(interrupt_mutex); - interrupted = 0xFFFF; - } - interrupt.notify_all(); - if (thread.joinable()) - thread.join(); - } + LogString taskName; + ThreadUtility::ManagerWeakPtr taskManager; }; FileWatchdog::FileWatchdog(const File& file1) @@ -86,20 +69,30 @@ FileWatchdog::FileWatchdog(const File& file1) FileWatchdog::~FileWatchdog() { - if (m_priv->thread.joinable()) - stop(); + stop(); } bool FileWatchdog::is_active() { - return m_priv->thread.joinable(); + bool result = false; + if (auto p = m_priv->taskManager.lock()) + result = p->value().hasPeriodicTask(m_priv->taskName); + return result; } void FileWatchdog::stop() { - LogLog::debug(LOG4CXX_STR("Stopping file watchdog")); - m_priv->stopWatcher(); + if (auto p = m_priv->taskManager.lock()) + p->value().removePeriodicTask(m_priv->taskName); +} + +/** +Stop all tasks that periodically checks for a file change. +*/ +void FileWatchdog::stopAll() +{ + ThreadUtility::instance()->removePeriodicTasksMatching(LOG4CXX_STR("WatchDog_")); } const File& FileWatchdog::file() @@ -141,50 +134,39 @@ void FileWatchdog::checkAndConfigure() } } -void FileWatchdog::run() -{ - if (LogLog::isDebugEnabled()) - { - LogString msg(LOG4CXX_STR("Checking [")); - msg += m_priv->file.getPath(); - msg += LOG4CXX_STR("] at "); - StringHelper::toString((int)m_priv->delay, m_priv->pool, msg); - msg += LOG4CXX_STR(" ms interval"); - LogLog::debug(msg); - } - - while (!is_interrupted()) - { - std::unique_lock lock( m_priv->interrupt_mutex ); - if (!m_priv->interrupt.wait_for( lock, std::chrono::milliseconds( m_priv->delay ), - std::bind(&FileWatchdog::is_interrupted, this) )) - checkAndConfigure(); - } - - if (LogLog::isDebugEnabled()) - { - LogString msg2(LOG4CXX_STR("Stop checking [")); - msg2 += m_priv->file.getPath(); - msg2 += LOG4CXX_STR("]"); - LogLog::debug(msg2); - } -} - void FileWatchdog::start() { + auto taskManager = ThreadUtility::instancePtr(); checkAndConfigure(); - if (!m_priv->thread.joinable()) + if (!taskManager->value().hasPeriodicTask(m_priv->taskName)) { - m_priv->interrupted = 0; - m_priv->thread = ThreadUtility::instance()->createThread(LOG4CXX_STR("FileWatchdog"), &FileWatchdog::run, this); + if (LogLog::isDebugEnabled()) + { + Pool p; + LogString msg(LOG4CXX_STR("Checking [")); + msg += m_priv->file.getPath(); + msg += LOG4CXX_STR("] at "); + StringHelper::toString((int)m_priv->delay, p, msg); + msg += LOG4CXX_STR(" ms interval"); + LogLog::debug(msg); + } + taskManager->value().addPeriodicTask(m_priv->taskName + , std::bind(&FileWatchdog::checkAndConfigure, this) + , std::chrono::milliseconds(m_priv->delay) + ); + m_priv->taskManager = taskManager; } } -bool FileWatchdog::is_interrupted() -{ - return m_priv->interrupted == 0xFFFF; -} - void FileWatchdog::setDelay(long delay1){ m_priv->delay = delay1; + auto p = m_priv->taskManager.lock(); + if (p && p->value().hasPeriodicTask(m_priv->taskName)) + { + p->value().removePeriodicTask(m_priv->taskName); + p->value().addPeriodicTask(m_priv->taskName + , std::bind(&FileWatchdog::checkAndConfigure, this) + , std::chrono::milliseconds(m_priv->delay) + ); + } } diff --git a/src/main/cpp/logmanager.cpp b/src/main/cpp/logmanager.cpp index 3fe235562..36fedd006 100644 --- a/src/main/cpp/logmanager.cpp +++ b/src/main/cpp/logmanager.cpp @@ -27,6 +27,7 @@ #include #include #include +#include #include #include @@ -203,6 +204,7 @@ LoggerList LogManager::getCurrentLoggers() void LogManager::shutdown() { APRInitializer::unregisterAll(); + ThreadUtility::instance()->removeAllPeriodicTasks(); getLoggerRepository()->shutdown(); } diff --git a/src/main/cpp/threadutility.cpp b/src/main/cpp/threadutility.cpp index d4211ce5a..72e872485 100644 --- a/src/main/cpp/threadutility.cpp +++ b/src/main/cpp/threadutility.cpp @@ -25,12 +25,23 @@ #include #include +#include +#include +#include #ifdef _WIN32 #include #include #endif +#if LOG4CXX_EVENTS_AT_EXIT +#include +#endif +#if !defined(LOG4CXX) + #define LOG4CXX 1 +#endif +#include + namespace LOG4CXX_NS { namespace helpers @@ -39,15 +50,57 @@ namespace helpers struct ThreadUtility::priv_data { priv_data() +#if LOG4CXX_EVENTS_AT_EXIT + : atExitRegistryRaii{ [this]{ stopThread(); } } +#endif + { + } + + ~priv_data() + { stopThread(); } + + ThreadStartPre start_pre{nullptr}; + ThreadStarted started{nullptr}; + ThreadStartPost start_post{nullptr}; + + using TimePoint = std::chrono::time_point; + struct NamedPeriodicFunction + { + LogString name; + Period delay; + TimePoint nextRun; + int errorCount; + std::function f; + }; + using JobStore = std::list; + JobStore jobs; + std::mutex job_mutex; + std::thread thread; + std::condition_variable interrupt; + std::mutex interrupt_mutex; + bool terminated{false}; + int retryCount{ 2 }; + Period maxDelay{ 0 }; + + void doPeriodicTasks(); + + void setTerminated() + { + std::lock_guard lock(interrupt_mutex); + terminated = true; + } + + void stopThread() { - start_pre = nullptr; - started = nullptr; - start_post = nullptr; + setTerminated(); + interrupt.notify_all(); + if (thread.joinable()) + thread.join(); } - ThreadStartPre start_pre; - ThreadStarted started; - ThreadStartPost start_post; +#if LOG4CXX_EVENTS_AT_EXIT + helpers::AtExitRegistry::Raii atExitRegistryRaii; +#endif }; #if LOG4CXX_HAS_PTHREAD_SIGMASK @@ -55,8 +108,8 @@ struct ThreadUtility::priv_data static thread_local bool sigmask_valid; #endif -ThreadUtility::ThreadUtility() : - m_priv( new priv_data() ) +ThreadUtility::ThreadUtility() + : m_priv( std::make_unique() ) { // Block signals by default. configureFuncs( std::bind( &ThreadUtility::preThreadBlockSignals, this ), @@ -66,10 +119,18 @@ ThreadUtility::ThreadUtility() : ThreadUtility::~ThreadUtility() {} +auto ThreadUtility::instancePtr() -> ManagerPtr +{ + auto result = APRInitializer::getOrAddUnique + ( []() -> ObjectPtr + { return std::make_shared(); } + ); + return result; +} + ThreadUtility* ThreadUtility::instance() { - static WideLife instance; - return &instance.value(); + return &instancePtr()->value(); } void ThreadUtility::configure( ThreadConfigurationType type ) @@ -198,5 +259,144 @@ ThreadStartPost ThreadUtility::postStartFunction() return m_priv->start_post; } +/** + * Add a periodic task + */ +void ThreadUtility::addPeriodicTask(const LogString& name, std::function f, const Period& delay) +{ + std::lock_guard lock(m_priv->job_mutex); + if (m_priv->maxDelay < delay) + m_priv->maxDelay = delay; + auto currentTime = std::chrono::system_clock::now(); + m_priv->jobs.push_back( priv_data::NamedPeriodicFunction{name, delay, currentTime + delay, 0, f} ); + if (!m_priv->thread.joinable()) + { + m_priv->terminated = false; + m_priv->thread = createThread(LOG4CXX_STR("log4cxx"), std::bind(&priv_data::doPeriodicTasks, m_priv.get())); + } + else + m_priv->interrupt.notify_one(); +} + +/** + * Is this already running a \c taskName periodic task? + */ +bool ThreadUtility::hasPeriodicTask(const LogString& name) +{ + std::lock_guard lock(m_priv->job_mutex); + auto pItem = std::find_if(m_priv->jobs.begin(), m_priv->jobs.end() + , [&name](const priv_data::NamedPeriodicFunction& item) + { return name == item.name; } + ); + return m_priv->jobs.end() != pItem; +} + +/** + * Remove all periodic tasks and stop the processing thread + */ +void ThreadUtility::removeAllPeriodicTasks() +{ + { + std::lock_guard lock(m_priv->job_mutex); + while (!m_priv->jobs.empty()) + m_priv->jobs.pop_back(); + } + m_priv->stopThread(); +} + +/** + * Remove the \c taskName periodic task + */ +void ThreadUtility::removePeriodicTask(const LogString& name) +{ + std::lock_guard lock(m_priv->job_mutex); + auto pItem = std::find_if(m_priv->jobs.begin(), m_priv->jobs.end() + , [&name](const priv_data::NamedPeriodicFunction& item) + { return name == item.name; } + ); + if (m_priv->jobs.end() != pItem) + { + m_priv->jobs.erase(pItem); + m_priv->interrupt.notify_one(); + } +} + +/** + * Remove any periodic task matching \c namePrefix + */ +void ThreadUtility::removePeriodicTasksMatching(const LogString& namePrefix) +{ + while (1) + { + std::lock_guard lock(m_priv->job_mutex); + auto pItem = std::find_if(m_priv->jobs.begin(), m_priv->jobs.end() + , [&namePrefix](const priv_data::NamedPeriodicFunction& item) + { return namePrefix.size() <= item.name.size() && item.name.substr(0, namePrefix.size()) == namePrefix; } + ); + if (m_priv->jobs.end() == pItem) + break; + m_priv->jobs.erase(pItem); + } + m_priv->interrupt.notify_one(); +} + +// Run ready tasks +void ThreadUtility::priv_data::doPeriodicTasks() +{ + while (!this->terminated) + { + auto currentTime = std::chrono::system_clock::now(); + TimePoint nextOperationTime = currentTime + this->maxDelay; + { + std::lock_guard lock(this->job_mutex); + if (this->jobs.empty()) + break; + for (auto& item : this->jobs) + { + if (this->terminated) + return; + if (item.nextRun <= currentTime) + { + try + { + item.f(); + item.nextRun = std::chrono::system_clock::now() + item.delay; + if (item.nextRun < nextOperationTime) + nextOperationTime = item.nextRun; + item.errorCount = 0; + } + catch (std::exception& ex) + { + LogLog::warn(item.name, ex); + ++item.errorCount; + } + catch (...) + { + LogLog::warn(item.name + LOG4CXX_STR(" threw an exception")); + ++item.errorCount; + } + } + else if (item.nextRun < nextOperationTime) + nextOperationTime = item.nextRun; + } + } + // Remove faulty tasks + while (1) + { + std::lock_guard lock(this->job_mutex); + auto pItem = std::find_if(this->jobs.begin(), this->jobs.end() + , [this](const NamedPeriodicFunction& item) + { return this->retryCount < item.errorCount; } + ); + if (this->jobs.end() == pItem) + break; + this->jobs.erase(pItem); + } + + std::unique_lock lock(this->interrupt_mutex); + this->interrupt.wait_until(lock, nextOperationTime); + } +} + } //namespace helpers } //namespace log4cxx diff --git a/src/main/include/log4cxx/fileappender.h b/src/main/include/log4cxx/fileappender.h index ebfd2dba9..87c843501 100644 --- a/src/main/include/log4cxx/fileappender.h +++ b/src/main/include/log4cxx/fileappender.h @@ -34,9 +34,12 @@ class Pool; /** * FileAppender appends log events to a file. * -*

Support for java.io.Writer and console appending -* has been deprecated and then removed. See the replacement -* solutions: WriterAppender and ConsoleAppender. +* Uses a background thread to periodically flush the output buffer +* when BufferedIO option is set true. +* Use the BufferedSeconds option to control the frequency, +* using 0 to disable the background output buffer flush. +* Refer to FileAppender::setOption() for more information. +* */ class LOG4CXX_EXPORT FileAppender : public WriterAppender { @@ -130,6 +133,7 @@ class LOG4CXX_EXPORT FileAppender : public WriterAppender FileName | {any} | - Append | True,False | True BufferedIO | True,False | False + BufferedSeconds | {any} | 5 ImmediateFlush | True,False | False BufferSize | (\ref fileSz1 "1") | 8 KB @@ -157,32 +161,54 @@ class LOG4CXX_EXPORT FileAppender : public WriterAppender int getBufferSize() const; /** + Get the number of seconds between file writes + when the BufferedIO option is true. + */ + int getBufferedSeconds() const; + + /** + Set file open mode to \c newValue. + The Append option takes a boolean value. It is set to true by default. If true, then File will be opened in append mode by #setFile (see above). Otherwise, setFile will open File in truncate mode. -

Note: Actual opening of the file is made when +

Note: The file is opened when #activateOptions is called, not when the options are set. */ - void setAppend(bool fileAppend1); + void setAppend(bool newValue); /** - The BufferedIO option takes a boolean value. It is set to - false by default. If true, then File - will be opened in buffered mode. + Set buffered output behavior to \c newValue. - BufferedIO will significantly increase performance on heavily - loaded systems. + By default buffered output is disabled and + this appender writes each log message directly to the file. + When buffered output is enabled, + log messages are stored into a memory buffer + and written to the file periodically or when the buffer is full. + Using buffered output will significantly reduce logging overhead. + + Note: Behavior change occurs when + #activateOptions is called, not when the options are set. + */ + void setBufferedIO(bool newValue); + + /** + Use \c newValue as the size of the output buffer. */ - void setBufferedIO(bool bufferedIO); + void setBufferSize(int newValue); /** - Set the size of the IO buffer. + Flush the output buffer every \c newValue seconds. + The default period is 5 seconds. + + Note: #activateOptions must be called after an option is changed + to activate the new frequency. */ - void setBufferSize(int bufferSize1); + void setBufferedSeconds(int newValue); /** * Replaces double backslashes with single backslashes diff --git a/src/main/include/log4cxx/helpers/filewatchdog.h b/src/main/include/log4cxx/helpers/filewatchdog.h index cbfc7b69b..2340fadcb 100644 --- a/src/main/include/log4cxx/helpers/filewatchdog.h +++ b/src/main/include/log4cxx/helpers/filewatchdog.h @@ -22,9 +22,6 @@ #include #include #include -#include -#include -#include namespace LOG4CXX_NS { @@ -57,24 +54,25 @@ class LOG4CXX_EXPORT FileWatchdog void setDelay(long delay); /** - Create a thread that periodically checks for a file change after first calling doOnChange() on the current thread. + Create an asynchronous task that periodically checks for a file change after first calling doOnChange(). */ void start(); /** - Stop the thread that periodically checks for a file change. + Stop the task that periodically checks for a file change. */ void stop(); /** - Is the thread that periodically checks for a file change running? + Is the task that periodically checks for a file change running? */ bool is_active(); + /** + Stop all tasks that periodically check for a file change. + */ + static void stopAll(); private: - void run(); - bool is_interrupted(); - FileWatchdog(const FileWatchdog&); FileWatchdog& operator=(const FileWatchdog&); diff --git a/src/main/include/log4cxx/helpers/singletonholder.h b/src/main/include/log4cxx/helpers/singletonholder.h new file mode 100644 index 000000000..85783e0d0 --- /dev/null +++ b/src/main/include/log4cxx/helpers/singletonholder.h @@ -0,0 +1,52 @@ +/* + * 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_SINGLETON_HOLDER_H +#define LOG4CXX_SINGLETON_HOLDER_H + +#include + +namespace LOG4CXX_NS +{ +namespace helpers +{ + +/** Wraps any singleton object so it can be added to APRInitializer + */ +template +class SingletonHolder : public Object +{ + using ThisType = SingletonHolder; + T m_data; + struct Unused : public helpers::Class + { + LogString getName() const override { return LOG4CXX_STR("SingletonHolder"); } + }; +public: // Object method stubs + const helpers::Class& getClass() const override { static Unused notUsed; return notUsed; } + BEGIN_LOG4CXX_CAST_MAP() + LOG4CXX_CAST_ENTRY(ThisType) + END_LOG4CXX_CAST_MAP() + +public: // Accessors + T& value() { return m_data; } +}; + +} // namespace helpers +} // namespace LOG4CXX_NS + +#endif //LOG4CXX_SINGLETON_HOLDER_H diff --git a/src/main/include/log4cxx/helpers/threadutility.h b/src/main/include/log4cxx/helpers/threadutility.h index 9d0127c53..583e8ff12 100644 --- a/src/main/include/log4cxx/helpers/threadutility.h +++ b/src/main/include/log4cxx/helpers/threadutility.h @@ -21,9 +21,10 @@ #include #include #include +#include #include "log4cxx/logstring.h" -#include "widelife.h" +#include "singletonholder.h" namespace LOG4CXX_NS { @@ -64,13 +65,10 @@ enum class ThreadConfigurationType BlockSignalsAndNameThread, }; -class ThreadUtility; -LOG4CXX_PTR_DEF(ThreadUtility); - class LOG4CXX_EXPORT ThreadUtility { private: - friend class LOG4CXX_NS::helpers::WideLife; + friend class SingletonHolder; ThreadUtility(); LOG4CXX_NS::helpers::ThreadStartPre preStartFunction(); @@ -153,6 +151,38 @@ class LOG4CXX_EXPORT ThreadUtility return t; } + + using Period = std::chrono::milliseconds; + + /** + * Add the \c taskName periodic task + */ + void addPeriodicTask(const LogString& taskName, std::function f, const Period& delay); + + /** + * Has a \c taskName periodic task already been added? + */ + bool hasPeriodicTask(const LogString& taskName); + + /** + * Remove all periodic tasks and stop the processing thread + */ + void removeAllPeriodicTasks(); + + /** + * Remove the \c taskName periodic task + */ + void removePeriodicTask(const LogString& taskName); + + /** + * Remove any periodic task matching \c namePrefix + */ + void removePeriodicTasksMatching(const LogString& namePrefix); + + using Manager = SingletonHolder; + LOG4CXX_PTR_DEF(Manager); + + static ManagerPtr instancePtr(); }; } /* namespace helpers */ diff --git a/src/main/include/log4cxx/private/fileappender_priv.h b/src/main/include/log4cxx/private/fileappender_priv.h index 11af7fbc0..c0fa78b28 100644 --- a/src/main/include/log4cxx/private/fileappender_priv.h +++ b/src/main/include/log4cxx/private/fileappender_priv.h @@ -20,6 +20,7 @@ #include #include +#include namespace LOG4CXX_NS { @@ -60,6 +61,18 @@ struct FileAppender::FileAppenderPriv : public WriterAppender::WriterAppenderPri /** How big should the IO buffer be? Default is 8K. */ int bufferSize; + + /** + The number of seconds between each asynchronous output buffer flush. + Only used when bufferedIO == true. + */ + int bufferedSeconds{ 5 }; + + /** + Manages asynchronous output buffer flush. + Only used when bufferedIO == true. + */ + helpers::ThreadUtility::ManagerWeakPtr taskManager; }; } diff --git a/src/main/include/log4cxx/private/writerappender_priv.h b/src/main/include/log4cxx/private/writerappender_priv.h index 30f52eea4..dc268cddc 100644 --- a/src/main/include/log4cxx/private/writerappender_priv.h +++ b/src/main/include/log4cxx/private/writerappender_priv.h @@ -37,7 +37,7 @@ struct WriterAppender::WriterAppenderPriv : public AppenderSkeleton::AppenderSke AppenderSkeletonPrivate(), immediateFlush(true) #if LOG4CXX_EVENTS_AT_EXIT - , atExitRegistryRaii([this]{atExitActivated();}) + , atExitRegistryRaii{ [this]{ flush(); } } #endif { } @@ -48,7 +48,7 @@ struct WriterAppender::WriterAppenderPriv : public AppenderSkeleton::AppenderSke immediateFlush(true), writer(writer1) #if LOG4CXX_EVENTS_AT_EXIT - , atExitRegistryRaii([this]{atExitActivated();}) + , atExitRegistryRaii{ [this]{flush();} } #endif { } @@ -57,19 +57,17 @@ struct WriterAppender::WriterAppenderPriv : public AppenderSkeleton::AppenderSke AppenderSkeletonPrivate(layout1), immediateFlush(true) #if LOG4CXX_EVENTS_AT_EXIT - , atExitRegistryRaii([this]{atExitActivated();}) + , atExitRegistryRaii{ [this]{flush();} } #endif { } -#if LOG4CXX_EVENTS_AT_EXIT - void atExitActivated() + void flush() { std::lock_guard lock(mutex); if (writer) writer->flush(pool); } -#endif /** Immediate flush means that the underlying writer or output stream diff --git a/src/test/cpp/fileappendertest.cpp b/src/test/cpp/fileappendertest.cpp index fb6e992b2..d432e2f4b 100644 --- a/src/test/cpp/fileappendertest.cpp +++ b/src/test/cpp/fileappendertest.cpp @@ -16,12 +16,35 @@ */ #include #include +#include #include #include "logunit.h" +#include using namespace log4cxx; using namespace log4cxx::helpers; +auto getLogger(const std::string& name = std::string()) -> LoggerPtr { + static struct log4cxx_initializer { + log4cxx_initializer() { + auto layout = std::make_shared(LOG4CXX_STR("%d %m%n")); + auto writer = std::make_shared(layout, LOG4CXX_STR("output/newdir/temp.log"), false); + writer->setName(LOG4CXX_STR("FileAppender")); + writer->setBufferedIO(true); + writer->setBufferedSeconds(1); + helpers::Pool p; + writer->activateOptions(p); + LogManager::getRootLogger()->addAppender(writer); + } + ~log4cxx_initializer() { + LogManager::shutdown(); + } + } initAndShutdown; + return name.empty() + ? LogManager::getRootLogger() + : LogManager::getLogger(name); +} + /** * @@ -33,6 +56,7 @@ LOGUNIT_CLASS(FileAppenderTest) LOGUNIT_TEST(testDirectoryCreation); LOGUNIT_TEST(testgetSetThreshold); LOGUNIT_TEST(testIsAsSevereAsThreshold); + LOGUNIT_TEST(testBufferedOutput); LOGUNIT_TEST_SUITE_END(); public: /** @@ -81,6 +105,25 @@ LOGUNIT_CLASS(FileAppenderTest) LevelPtr debug = Level::getDebug(); LOGUNIT_ASSERT(appender->isAsSevereAsThreshold(debug)); } + + void testBufferedOutput() + { + auto logger = getLogger(); + int requiredMsgCount = 10000; + for ( int x = 0; x < requiredMsgCount; x++ ) + { + LOG4CXX_INFO( logger, "This is test message " << x ); + } + auto appender = log4cxx::cast(logger->getAppender(LOG4CXX_STR("FileAppender"))); + LOGUNIT_ASSERT(appender); + File file(appender->getFile()); + Pool p; + size_t initialLength = file.length(p); + + // wait 1.1 sec and check the buffer is flushed + apr_sleep(1100000); + LOGUNIT_ASSERT(initialLength < file.length(p)); + } }; LOGUNIT_TEST_SUITE_REGISTRATION(FileAppenderTest);