8000 Remove mutexes from Logging (#14550) · arangodb/arangodb@aad0dd2 · GitHub
[go: up one dir, main page]
Skip to content

Commit aad0dd2

Browse files
jsteemannmpoeter
jsteemann
and
mpoeter
authored
Remove mutexes from Logging (#14550)
Co-authored-by: mpoeter <manuel@arangodb.com>
1 parent f34edd0 commit aad0dd2

File tree

7 files changed

+81
-52
lines changed

7 files changed

+81
-52
lines changed

‎arangod/Agency/Constituent.h‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -28,6 +28,7 @@
2828
#include "AgentConfiguration.h"
2929
#include "Basics/Common.h"
3030
#include "Basics/ConditionVariable.h"
31+
#include "Basics/Mutex.h"
3132
#include "Basics/Thread.h"
3233
#include "RestServer/MetricsFeature.h"
3334

‎arangod/Cluster/MaintenanceFeature.h‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -27,6 +27,7 @@
2727
#include "ApplicationFeatures/ApplicationFeature.h"
2828
#include "Basics/Common.h"
2929
#include "Basics/ConditionVariable.h"
30+
#include "Basics/Mutex.h"
3031
#include "Basics/ReadWriteLock.h"
3132
#include "Basics/Result.h"
3233
#include "Cluster/Action.h"

‎lib/Logger/LogThread.cpp‎

Lines changed: 0 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -33,7 +33,6 @@ LogThread::LogThread(application_features::ApplicationServer& server, std::strin
3333
: Thread(server, name), _messages(64) {}
3434

3535
LogThread::~LogThread() {
36-
Logger::_threaded = false;
3736
Logger::_active = false;
3837

3938
shutdown();

‎lib/Logger/LogTopic.cpp‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -27,6 +27,7 @@
2727

2828
#include "LogTopic.h"
2929

30+
#include "Basics/Mutex.h"
3031
#include "Basics/MutexLocker.h"
3132
#include "Logger/LogMacros.h"
3233
#include "Logger/Logger.h"

‎lib/Logger/Logger.cpp‎

Lines changed: 58 additions & 44 deletions
< 9E88 td data-grid-cell-id="diff-e601a8c95e48d4c449cba6ae2f3b60ef2767645c725a38c02d76ceb255cef89a-748-756-1" data-selected="false" role="gridcell" style="background-color:var(--diffBlob-additionNum-bgColor, var(--diffBlob-addition-bgColor-num));text-align:center" tabindex="-1" valign="top" class="focusable-grid-cell diff-line-number position-relative left-side">756
Original file line numberDiff line numberDiff line change
@@ -32,8 +32,6 @@
3232

3333
#include "Basics/Common.h"
3434
#include "Basics/Exceptions.h"
35-
#include "Basics/Mutex.h"
36-
#include "Basics/MutexLocker.h"
3735
#include "Basics/StringUtils.h"
3836
#include "Basics/Thread.h"
3937
#include "Basics/application-exit.h"
@@ -111,8 +109,6 @@ void LogMessage::shrink(std::size_t maxLength) {
111109
}
112110

113111

114-
Mutex Logger::_initializeMutex;
115-
116112
std::atomic<bool> Logger::_active(false);
117113
std::atomic<LogLevel> Logger::_level(LogLevel::INFO);
118114

@@ -123,7 +119,6 @@ bool Logger::_shortenFilenames(true);
123119
bool Logger::_showProcessIdentifier(true);
124120
bool Logger::_showThreadIdentifier(false);
125121
bool Logger::_showThreadName(false);
126-
bool Logger::_threaded(false);
127122
bool Logger::_useColor(true);
128123
bool Logger::_useEscaped(true);
129124
bool Logger::_keepLogRotate(false);
@@ -135,8 +130,22 @@ TRI_pid_t Logger::_cachedPid(0);
135130
std::string Logger::_outputPrefix;
136131
std::string Logger::_hostname;
137132

138-
std::unique_ptr<LogThread> Logger::_loggingThread(nullptr);
133+
std::atomic<std::size_t> Logger::_loggingThreadRefs(0);
134+
std::atomic<LogThread*> Logger::_loggingThread(nullptr);
135+
136+
Logger::ThreadRef::ThreadRef() {
137+
// (1) - this acquire-fetch-add synchronizes with the release-fetch-add (5)
138+
Logger::_loggingThreadRefs.fetch_add(1, std::memory_order_acquire);
139+
// (2) - this acquire-load synchronizes with the release-store (4)
140+
_thread = Logger::_loggingThread.load(std::memory_order_acquire);
141+
}
139142

143+
Logger::ThreadRef::~ThreadRef() {
144+
// (3) - this relaxed-fetch-add is potentially part of a release-sequence
145+
// headed by (5)
146+
Logger::_loggingThreadRefs.fetch_sub(1, std::memory_order_relaxed);
147+
}
148+
140149
LogGroup& Logger::defaultLogGroup() { return ::defaultLogGroupInstance; }
141150

142151
LogLevel Logger::logLevel() { return _level.load(std::memory_order_relaxed); }
@@ -676,14 +685,19 @@ void Logger::append(LogGroup& group,
676685
// note that these loggers do not require any configuration so we can always and safely invoke them.
677686
LogAppender::logGlobal(group, *msg);
678687

679-
if (!_active.load(std::memory_order_relaxed)) {
688+
if (!_active.load(std::memory_order_acquire)) {
680689
// logging is still turned off. now use hard-coded to-stderr logging
681690
inactive(msg);
682691
} else {
683692
// now either queue or output the message
684693
bool handled = false;
685-
if (_threaded && !forceDirect) {
686-
handled = _loggingThread->log(group, msg);
694+
if (!forceDirect) {
695+
// check if we have a logging thread
696+
ThreadRef loggingThread;
697+
698+
if (loggingThread) {
699+
handled = loggingThread->log(group, msg);
700+
}
687701
}
688702

689703
if (!handled) {
@@ -704,64 +718,69 @@ void Logger::append(LogGroup& group,
704718
////////////////////////////////////////////////////////////////////////////////
705719

706720
void Logger::initialize(application_features::ApplicationServer& server, bool threaded) {
707-
MUTEX_LOCKER(locker, _initializeMutex);
708-
709-
if (_active.exchange(true)) {
721+
if (_active.exchange(true, std::memory_order_acquire)) {
710722
THROW_ARANGO_EXCEPTION_MESSAGE(TRI_ERROR_INTERNAL,
711723
"Logger already initialized");
712724
}
713725

714726
// logging is now active
715-
TRI_ASSERT(_active);
716-
717727
if (threaded) {
718-
_loggingThread = std::make_unique<LogThread>(server, ::LogThreadName);
719-
if (!_loggingThread->start()) {
728+
auto loggingThread = std::make_unique<LogThread>(server, ::LogThreadName);
729+
if (!loggingThread->start()) {
720730
LOG_TOPIC("28bd9", FATAL, arangodb::Logger::FIXME)
721731
<< "could not start logging thread";
722732
FATAL_ERROR_EXIT();
723733
}
724-
}
725734

726-
// generate threaded logging?
727-
_threaded = threaded;
735+
// (4) - this release-store synchronizes with the acquire-load (2)
736+
_loggingThread.store(loggingThread.release(), std::memory_order_release);
737+
}
728738
}
729739

730740
////////////////////////////////////////////////////////////////////////////////
731741
/// @brief shuts down the logging components
732742
////////////////////////////////////////////////////////////////////////////////
733743

734744
void Logger::shutdown() {
735-
MUTEX_LOCKER(locker, _initializeMutex);
736-
737-
if (!_active.exchange(false)) {
738-
// if logging not activated or already shutdown, then we can abort here
745+
if (!_active.exchange(false, std::memory_order_acquire)) {
746+
// if logging not activated or already shut down, then we can abort here
739747
return;
740748
}
749+
// logging is now inactive
741750

742-
TRI_ASSERT(!_active);
743-
751+
// reset the instance variable in Logger, so that others won't see it anymore
752+
std::unique_ptr<LogThread> loggingThread(_loggingThread.exchange(nullptr, std::memory_order_relaxed));
753+
744754
// logging is now inactive (this will terminate the logging thread)
745755
// join with the logging thread
746-
if (_threaded) {
747-
_threaded = false;
748-
+
if (loggingThread != nullptr) {
757+
// (5) - this release-fetch-add synchronizes with the acquire-fetch-add (1)
758+
// Even though a fetch-add with 0 is essentially a noop, this is necessary to
759+
// ensure that threads which try to get a reference to the _loggingThread
760+
// actually see the new nullptr value.
761+
_loggingThreadRefs.fetch_add(0, std::memory_order_release);
762+
763+
// wait until all threads have dropped their reference to the logging thread
764+
while (_loggingThreadRefs.load(std::memory_order_relaxed)) {
765+
std::this_thread::sleep_for(std::chrono::milliseconds(20));
766+
}
767+
749768
char const* currentThreadName = Thread::currentThreadName();
750769
if (currentThreadName != nullptr && ::LogThreadName == currentThreadName) {
751770
// oops, the LogThread itself crashed...
752771
// so we need to flush the log messages here ourselves - if we waited for
753772
// the LogThread to flush them, we would wait forever.
754-
_loggingThread->processPendingMessages();
755-
_loggingThread->beginShutdown();
773+
loggingThread->processPendingMessages();
774+
loggingThread->beginShutdown();
756775
} else {
757776
int tries = 0;
758-
while (_loggingThread->hasMessages() && ++tries < 10) {
759-
_loggingThread->wakeup();
777+
while (loggingThread->hasMessages() && ++tries < 10) {
778+
loggingThread->wakeup();
760779
std::this_thread::sleep_for(std::chrono::milliseconds(10));
761780
}
762-
_loggingThread->beginShutdown();
781+
loggingThread->beginShutdown();
763782
// wait until logging thread has logged all active messages
764-
while (_loggingThread->isRunning()) {
783+
while (loggingThread->isRunning()) {
765784
std::this_thread::sleep_for(std::chrono::milliseconds(10));
766785
}
767786
}
@@ -773,23 +792,18 @@ void Logger::shutdown() {
773792
_cachedPid = 0;
774793
}
775794

776-
void Logger::shutdownLogThread() {
777-
_loggingThread.reset();
778-
}
779-
780795
////////////////////////////////////////////////////////////////////////////////
781796
/// @brief tries to flush the logging
782797
////////////////////////////////////////////////////////////////////////////////
783798

784799
void Logger::flush() noexcept {
785-
MUTEX_LOCKER(locker, _initializeMutex);
786-
787-
if (!_active) {
800+
if (!_active.load(std::memory_order_acquire)) {
788801
// logging not (or not yet) initialized
789802
return;
790803
}
791-
792-
if (_threaded && _loggingThread != nullptr) {
793-
_loggingThread->flush();
804+
805+
ThreadRef loggingThread;
806+
if (loggingThread) {
807+
loggingThread->flush();
794808
}
795809
}

‎lib/Logger/Logger.h‎

Lines changed: 20 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -63,7 +63,6 @@
6363
#include <vector>
6464

6565
#include "Basics/Common.h"
66-
#include "Basics/Mutex.h"
6766
#include "Basics/threads.h"
6867
#include "Logger/LogLevel.h"
6968
#include "Logger/LogTimeFormat.h"
@@ -313,12 +312,9 @@ class Logger {
313312
public:
314313
static void initialize(application_features::ApplicationServer&, bool);
315314
static void shutdown();
316-
static void shutdownLogThread();
317315
static void flush() noexcept;
318316

319317
private:
320-
static Mutex _initializeMutex;
321-
322318
// these variables might be changed asynchronously
323319
static std::atomic<bool> _active;
324320
static std::atomic<LogLevel> _level;
@@ -331,7 +327,6 @@ class Logger {
331327
static bool _showThreadIdentifier;
332328
static bool _showThreadName;
333329
static bool _showRole;
334-
static bool _threaded;
335330
static bool _useColor;
336331
static bool _useEscaped;
337332
static bool _keepLogRotate;
@@ -343,6 +338,25 @@ class Logger {
343338
static std::string _outputPrefix;
344339
static std::string _hostname;
345340

346-
static std::unique_ptr<LogThread> _loggingThread;
341+
struct ThreadRef {
342+
ThreadRef();
343+
~ThreadRef();
344+
345+
ThreadRef(const ThreadRef&) = delete;
346+
ThreadRef(ThreadRef&&) = delete;
347+
ThreadRef& operator=(const ThreadRef&) = delete;
348+
ThreadRef& operator=(ThreadRef&&) = delete;
349+
350+
LogThread* operator->() const noexcept { return _thread; }
351+
operator bool() const noexcept { return _thread != nullptr; }
352+
private:
353+
LogThread* _thread;
354+
};
355+
356+
// logger thread. only populated when threaded logging is selected.
357+
// the pointer must only be used with atomic accessors after the ref counter
358+
// has been increased. Best to usethe ThreadRef class for this!
359+
static std::atomic<std::size_t> _loggingThreadRefs;
360+
static std::atomic<LogThread*> _loggingThread;
347361
};
348362
} // namespace arangodb

‎lib/Logger/LoggerFeature.cpp‎

Lines changed: 0 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -92,7 +92,6 @@ LoggerFeature::LoggerFeature(application_features::ApplicationServer& server,
9292

9393
LoggerFeature::~LoggerFeature() {
9494
Logger::shutdown();
95-
Logger::shutdownLogThread();
9695
}
9796

9897
void LoggerFeature::collectOptions(std::shared_ptr<ProgramOptions> options) {

0 commit comments

Comments
 (0)
0