Fix filesink drop messages improved (#479)

* Fix FileSink dropping messages introduced by 'optionable buffer to x messages' feature
Commit 6c6122fafc introduced a bug where 99 out of 100 logs were actually dumped

* Updated unit tests to trigger sink flush bug
---------

Co-authored-by: Ryan Ammoury <ryan.ammoury@squadrone-system.com>
This commit is contained in:
Kjell Hedström 2023-02-20 06:16:34 -07:00 committed by GitHub
parent 43f5eddcdd
commit 4f1224b9d5
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
4 changed files with 11 additions and 6 deletions

View File

@ -68,7 +68,7 @@ endif()
# Calculate the version number # Calculate the version number
SET(MAJOR_VERSION 2) SET(MAJOR_VERSION 2)
SET(MINOR_VERSION 2) SET(MINOR_VERSION 3)
IF ( NOT VERSION ) IF ( NOT VERSION )
IF ( "${CMAKE_HOST_SYSTEM_NAME}" STREQUAL "Windows" ) IF ( "${CMAKE_HOST_SYSTEM_NAME}" STREQUAL "Windows" )

View File

@ -62,12 +62,11 @@ namespace g3 {
_firstEntry = false; _firstEntry = false;
} }
std::ofstream &out(filestream());
auto data = message.get().toString(_log_details_func); auto data = message.get().toString(_log_details_func);
_write_buffer.append(data); _write_buffer.append(data);
if (++_write_counter % _write_to_log_every_x_message == 0) { if (++_write_counter % _write_to_log_every_x_message == 0) {
out << message.get().toString(_log_details_func) << std::flush; filestream() << _write_buffer << std::flush;
_write_buffer.clear(); _write_buffer.clear();
} }
} }

View File

@ -155,12 +155,16 @@ TEST(Basics, Shutdown) {
std::string file_content; std::string file_content;
{ {
RestoreFileLogger logger(log_directory); RestoreFileLogger logger(log_directory);
LOG(INFO) << "First message buffered, then flushed";
LOG(INFO) << "Second message still in the buffer";
LOG(INFO) << "Not yet shutdown. This message should make it"; LOG(INFO) << "Not yet shutdown. This message should make it";
logger.reset(); // force flush of logger (which will trigger a shutdown) logger.reset(); // force flush of logger (which will trigger a shutdown)
LOG(INFO) << "Logger is shutdown,. this message will not make it (but it's safe to try)"; LOG(INFO) << "Logger is shutdown,. this message will not make it (but it's safe to try)";
file_content = readFileToText(logger.logFile()); // logger is already reset file_content = readFileToText(logger.logFile()); // logger is already reset
SCOPED_TRACE("LOG_INFO"); // Scope exit be prepared for destructor failure SCOPED_TRACE("LOG_INFO"); // Scope exit be prepared for destructor failure
} }
EXPECT_TRUE(verifyContent(file_content, "First message buffered, then flushed"));
EXPECT_TRUE(verifyContent(file_content, "Second message still in the buffer"));
EXPECT_TRUE(verifyContent(file_content, "Not yet shutdown. This message should make it")); EXPECT_TRUE(verifyContent(file_content, "Not yet shutdown. This message should make it"));
EXPECT_FALSE(verifyContent(file_content, "Logger is shutdown,. this message will not make it (but it's safe to try)")); EXPECT_FALSE(verifyContent(file_content, "Logger is shutdown,. this message will not make it (but it's safe to try)"));
} }

View File

@ -26,7 +26,8 @@ namespace testing_helpers {
std::string g_mockFatal_message = {}; std::string g_mockFatal_message = {};
int g_mockFatal_signal = -1; int g_mockFatal_signal = -1;
bool g_mockFatalWasCalled = false; bool g_mockFatalWasCalled = false;
const size_t kFlushToDiskWithThisInterval = 2;
std::string mockFatalMessage() { std::string mockFatalMessage() {
return g_mockFatal_message; return g_mockFatal_message;
} }
@ -110,7 +111,8 @@ namespace testing_helpers {
} }
RestoreFileLogger::RestoreFileLogger(std::string directory) RestoreFileLogger::RestoreFileLogger(std::string directory)
: _scope(new ScopedLogger), _handle(_scope->get()->addSink(std::make_unique<g3::FileSink>("UNIT_TEST_LOGGER", directory), &g3::FileSink::fileWrite)) { : _scope(new ScopedLogger), _handle(_scope->get()->addSink(std::make_unique<g3::FileSink>("UNIT_TEST_LOGGER",
directory, "g3log", kFlushToDiskWithThisInterval), &g3::FileSink::fileWrite)) {
using namespace g3; using namespace g3;
g3::initializeLogging(_scope->_currentWorker.get()); g3::initializeLogging(_scope->_currentWorker.get());
clearMockFatal(); clearMockFatal();
@ -133,7 +135,7 @@ namespace testing_helpers {
reset(); reset();
if (!removeFile(_log_file)) if (!removeFile(_log_file))
ADD_FAILURE(); ADD_FAILURE();
} }
std::string RestoreFileLogger::logFile() { std::string RestoreFileLogger::logFile() {