Skip to content

Commit

Permalink
Reduce MultiprocessRollingFileAppender overhead
Browse files Browse the repository at this point in the history
  • Loading branch information
stephen-webb committed Dec 15, 2024
1 parent e096ae3 commit 2de970c
Show file tree
Hide file tree
Showing 2 changed files with 73 additions and 38 deletions.
50 changes: 12 additions & 38 deletions src/main/cpp/multiprocessrollingfileappender.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -101,8 +101,6 @@ class MultiprocessOutputStream : public OutputStream
rfa->setFileLength(File().setPath(rfa->getFile()).length(p));
}
}

static FileOutputStreamPtr getFileOutputStream(MultiprocessRollingFileAppender* rfa);
};
} // namespace rolling
} // namespace LOG4CXX_NS
Expand All @@ -121,6 +119,7 @@ struct MultiprocessRollingFileAppender::MultiprocessRollingFileAppenderPriv
apr_file_close(lock_file);
}

apr_file_t* log_file = NULL;
apr_file_t* lock_file = NULL;

public: // Support classes
Expand Down Expand Up @@ -198,39 +197,6 @@ struct MultiprocessRollingFileAppender::MultiprocessRollingFileAppenderPriv
};
};

FileOutputStreamPtr
MultiprocessOutputStream::getFileOutputStream(MultiprocessRollingFileAppender* rfa)
{
auto writer = rfa->getWriter();
FileOutputStreamPtr result;
auto osw = LOG4CXX_NS::cast<OutputStreamWriter>(writer);
if( !osw )
{
if (auto bw = LOG4CXX_NS::cast<BufferedWriter>(writer))
osw = LOG4CXX_NS::cast<OutputStreamWriter>(bw->getWriter());
}
if( !osw ){
LogString msg(LOG4CXX_STR("Can't cast writer to OutputStreamWriter"));
msg += LOG4CXX_STR(" - Rollover synchronization will be degraded.");
rfa->m_priv->errorHandler->error(msg);
return result;
}
auto cos = LOG4CXX_NS::cast<MultiprocessOutputStream>(osw->getOutputStreamPtr());
if( !cos ){
LogString msg(LOG4CXX_STR("Can't cast stream to MultiprocessOutputStream"));
msg += LOG4CXX_STR(" - Rollover synchronization will be degraded.");
rfa->m_priv->errorHandler->error(msg);
return result;
}
result = LOG4CXX_NS::cast<FileOutputStream>(cos->os);
if( !result ){
LogString msg(LOG4CXX_STR("Can't cast stream to FileOutputStream"));
msg += LOG4CXX_STR(" - Rollover synchronization will be degraded.");
rfa->m_priv->errorHandler->error(msg);
}
return result;
}

#define _priv static_cast<MultiprocessRollingFileAppenderPriv*>(m_priv.get())

IMPLEMENT_LOG4CXX_OBJECT(MultiprocessRollingFileAppender)
Expand Down Expand Up @@ -259,14 +225,13 @@ void MultiprocessRollingFileAppender::activateOptions(Pool& p)
*/
bool MultiprocessRollingFileAppender::isAlreadyRolled(const LogString& fileName, size_t* pSize)
{
auto fos = MultiprocessOutputStream::getFileOutputStream(this);
if( !fos )
if( !_priv->log_file )
return false;
apr_int32_t wantedInfo = APR_FINFO_IDENT;
if (pSize)
wantedInfo |= APR_FINFO_SIZE;
apr_finfo_t finfo1;
apr_status_t st1 = apr_file_info_get(&finfo1, wantedInfo, fos->getFilePtr());
apr_status_t st1 = apr_file_info_get(&finfo1, wantedInfo, _priv->log_file);

if (st1 != APR_SUCCESS)
LogLog::warn(LOG4CXX_STR("apr_file_info_get failed"));
Expand Down Expand Up @@ -495,6 +460,15 @@ void MultiprocessRollingFileAppender::subAppend(const LoggingEventPtr& event, Po
*/
WriterPtr MultiprocessRollingFileAppender::createWriter(OutputStreamPtr& os)
{
auto fos = LOG4CXX_NS::cast<FileOutputStream>(os);
if( fos )
_priv->log_file = fos->getFilePtr();
else
{
LogString msg(LOG4CXX_STR("Can't cast stream to FileOutputStream"));
msg += LOG4CXX_STR(" - Rollover synchronization will be degraded.");
_priv->errorHandler->error(msg);
}
OutputStreamPtr cos = std::make_shared<MultiprocessOutputStream>(os, this);
return FileAppender::createWriter(cos);
}
Expand Down
61 changes: 61 additions & 0 deletions src/test/cpp/benchmark/benchmark.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -7,6 +7,10 @@
#include <log4cxx/asyncappender.h>
#include <log4cxx/net/smtpappender.h>
#include <log4cxx/fileappender.h>
#if LOG4CXX_HAS_MULTIPROCESS_ROLLING_FILE_APPENDER
#include <log4cxx/rolling/multiprocessrollingfileappender.h>
#include <log4cxx/rolling/timebasedrollingpolicy.h>
#endif
#include <log4cxx/private/appenderskeleton_priv.h>
#if LOG4CXX_USING_STD_FORMAT
#include <format>
Expand Down Expand Up @@ -65,6 +69,25 @@ class BenchmarkFileAppender : public FileAppender
}
};

#if LOG4CXX_HAS_MULTIPROCESS_ROLLING_FILE_APPENDER
class BenchmarkMultiprocessFileAppender : public rolling::MultiprocessRollingFileAppender
{
public:
BenchmarkMultiprocessFileAppender(const LayoutPtr& layout)
{
setLayout(layout);
auto tempDir = helpers::OptionConverter::getSystemProperty(LOG4CXX_STR("TEMP"), LOG4CXX_STR("/tmp"));
auto policy = std::make_shared<rolling::TimeBasedRollingPolicy>();
policy->setFileNamePattern(tempDir + LOG4CXX_STR("/") + LOG4CXX_STR("multiprocess-%d{yyyy-MM-dd-HH-mm-ss-SSS}.log"));
setRollingPolicy(policy);
setFile(tempDir + LOG4CXX_STR("/") + LOG4CXX_STR("multiprocess.log"));
setBufferedIO(true);
helpers::Pool p;
activateOptions(p);
}
};
#endif

void disableThousandSeparatorsInJSON()
{
std::setlocale(LC_ALL, "C"); /* Set locale for C functions */
Expand All @@ -77,6 +100,9 @@ class benchmarker : public ::benchmark::Fixture
LoggerPtr m_logger = getLogger();
LoggerPtr m_asyncLogger = getAsyncLogger();
LoggerPtr m_fileLogger = getFileLogger();
#if LOG4CXX_HAS_MULTIPROCESS_ROLLING_FILE_APPENDER
LoggerPtr m_multiprocessLogger = getMultiprocessLogger();
#endif

public: // Class methods
static int threadCount()
Expand Down Expand Up @@ -175,6 +201,27 @@ class benchmarker : public ::benchmark::Fixture
}
return result;
}

#if LOG4CXX_HAS_MULTIPROCESS_ROLLING_FILE_APPENDER
static LoggerPtr getMultiprocessLogger()
{
LogString name = LOG4CXX_STR("benchmark.fixture.multiprocess");
auto r = LogManager::getLoggerRepository();
LoggerPtr result;
if (!(result = r->exists(name)))
{
result = r->getLogger(name);
result->setAdditivity(false);
result->setLevel(Level::getInfo());
auto writer = std::make_shared<BenchmarkMultiprocessFileAppender>(std::make_shared<PatternLayout>(LOG4CXX_STR("%d %m%n")));
writer->setName(LOG4CXX_STR("MultiprocessFileAppender"));
helpers::Pool p;
writer->activateOptions(p);
result->addAppender(writer);
}
return result;
}
#endif
};

BENCHMARK_DEFINE_F(benchmarker, logDisabledTrace)(benchmark::State& state)
Expand Down Expand Up @@ -310,5 +357,19 @@ BENCHMARK_DEFINE_F(benchmarker, fileIntPlusFloatValueMessageBuffer)(benchmark::S
BENCHMARK_REGISTER_F(benchmarker, fileIntPlusFloatValueMessageBuffer)->Name("Logging int+float using MessageBuffer, pattern: %d %m%n");
BENCHMARK_REGISTER_F(benchmarker, fileIntPlusFloatValueMessageBuffer)->Name("Logging int+float using MessageBuffer, pattern: %d %m%n")->Threads(benchmarker::threadCount());

#if LOG4CXX_HAS_MULTIPROCESS_ROLLING_FILE_APPENDER
BENCHMARK_DEFINE_F(benchmarker, multiprocessFileIntPlusFloatValueMessageBuffer)(benchmark::State& state)
{
int x = 0;
for (auto _ : state)
{
auto f = static_cast<float>(rand()) / static_cast<float>(RAND_MAX);
LOG4CXX_INFO( m_multiprocessLogger, "Hello: message number " << ++x
<< " pseudo-random float " << std::setprecision(3) << std::fixed << f);
}
}
BENCHMARK_REGISTER_F(benchmarker, multiprocessFileIntPlusFloatValueMessageBuffer)->Name("Multiprocess logging int+float using MessageBuffer, pattern: %d %m%n");
#endif

BENCHMARK_MAIN();

0 comments on commit 2de970c

Please sign in to comment.