From fa1719acc3477c6c0071b66d1ef200d1e7184d07 Mon Sep 17 00:00:00 2001 From: Matthias Koefferlein Date: Tue, 23 Mar 2021 22:45:45 +0100 Subject: [PATCH] Avoid a deadlock in the logger system --- src/lay/lay/layLogViewerDialog.cc | 51 ++++++++++++++++++++----------- src/lay/lay/layLogViewerDialog.h | 6 ++++ src/laybasic/laybasic/gtf.cc | 1 + src/tl/tl/tlLog.cc | 18 +++++++++++ src/tl/tl/tlLog.h | 2 ++ src/tl/tl/tlUnitTest.h | 1 + src/unit_tests/utTestConsole.cc | 8 +++++ 7 files changed, 69 insertions(+), 18 deletions(-) diff --git a/src/lay/lay/layLogViewerDialog.cc b/src/lay/lay/layLogViewerDialog.cc index b0b4f3b23..27b8ce6db 100644 --- a/src/lay/lay/layLogViewerDialog.cc +++ b/src/lay/lay/layLogViewerDialog.cc @@ -84,6 +84,12 @@ LogReceiver::endl () } } +void +LogReceiver::yield () +{ + mp_file->yield (); +} + void LogReceiver::end () { @@ -223,30 +229,36 @@ LogFile::max_entries () const void LogFile::add (LogFileEntry::mode_type mode, const std::string &msg, bool continued) +{ + QMutexLocker locker (&m_lock); + + if (m_max_entries == 0) { + return; + } + + if (m_messages.size () >= m_max_entries) { + m_messages.pop_front (); + } + + if (mode == LogFileEntry::Warning || mode == LogFileEntry::WarningContinued) { + m_has_warnings = true; + } else if (mode == LogFileEntry::Error || mode == LogFileEntry::ErrorContinued) { + m_has_errors = true; + } + + m_messages.push_back (LogFileEntry (mode, msg, continued)); + + ++m_generation_id; +} + +void +LogFile::yield () { bool can_yield = false; { QMutexLocker locker (&m_lock); - if (m_max_entries == 0) { - return; - } - - if (m_messages.size () >= m_max_entries) { - m_messages.pop_front (); - } - - if (mode == LogFileEntry::Warning || mode == LogFileEntry::WarningContinued) { - m_has_warnings = true; - } else if (mode == LogFileEntry::Error || mode == LogFileEntry::ErrorContinued) { - m_has_errors = true; - } - - m_messages.push_back (LogFileEntry (mode, msg, continued)); - - ++m_generation_id; - if (lay::ApplicationBase::instance ()->qapp_gui () && QThread::currentThread () == lay::ApplicationBase::instance ()->qapp_gui ()->thread () && (tl::Clock::current () - m_last_yield).seconds () > 0.1) { m_last_yield = tl::Clock::current (); can_yield = true; @@ -254,6 +266,9 @@ LogFile::add (LogFileEntry::mode_type mode, const std::string &msg, bool continu } // use this opportunity to process events + // NOTE: as process events may trigger further log output, it's necessary to do process events outside any other + // method (e.g. add) which is subject to locking. Hence we avoid deadlocks. + // We accept the risk of recursion inside process_events as we have a timeout before accepting new yield calls. if (can_yield) { lay::ApplicationBase::instance ()->process_events (QEventLoop::AllEvents); } diff --git a/src/lay/lay/layLogViewerDialog.h b/src/lay/lay/layLogViewerDialog.h index 340b28ed0..4f6725fe8 100644 --- a/src/lay/lay/layLogViewerDialog.h +++ b/src/lay/lay/layLogViewerDialog.h @@ -90,6 +90,7 @@ protected: virtual void endl (); virtual void end (); virtual void begin (); + virtual void yield (); private: LogFile *mp_file; @@ -193,6 +194,11 @@ public slots: return m_log_receiver; } + /** + * @brief Implementation of post-log action + */ + void yield (); + /** * @brief Sets the maximum number of entries to show * diff --git a/src/laybasic/laybasic/gtf.cc b/src/laybasic/laybasic/gtf.cc index a5197dca5..6e6fc1171 100644 --- a/src/laybasic/laybasic/gtf.cc +++ b/src/laybasic/laybasic/gtf.cc @@ -1112,6 +1112,7 @@ protected: virtual void endl () { mp_rec->errlog_endl (); } virtual void end () { mp_rec->errlog_end (); } virtual void begin () { mp_rec->errlog_begin (); } + virtual void yield () { } private: Recorder *mp_rec; diff --git a/src/tl/tl/tlLog.cc b/src/tl/tl/tlLog.cc index c615fa741..bfb5aafc9 100644 --- a/src/tl/tl/tlLog.cc +++ b/src/tl/tl/tlLog.cc @@ -99,6 +99,9 @@ Channel::release_proxy () m_active = false; m_no_endl = false; m_lock.unlock (); + + // after we have released the lock we give the receivers an opportunity to process events + yield (); } ChannelEndl endl; @@ -160,6 +163,18 @@ LogTee::puts (const char *s) } } +void +LogTee::yield () +{ + try { + for (tl::weak_collection::iterator c = m_channels.begin (); c != m_channels.end (); ++c) { + c->yield (); + } + } catch (...) { + // ignore exceptions here + } +} + void LogTee::endl () { @@ -270,6 +285,7 @@ protected: virtual void endl (); virtual void end (); virtual void begin (); + virtual void yield () { } private: int m_verbosity; @@ -342,6 +358,7 @@ protected: virtual void endl (); virtual void end (); virtual void begin (); + virtual void yield () { } private: bool m_colorized; @@ -406,6 +423,7 @@ protected: virtual void endl (); virtual void end (); virtual void begin (); + virtual void yield () { } private: bool m_colorized; diff --git a/src/tl/tl/tlLog.h b/src/tl/tl/tlLog.h index 803aa2cc1..b085a14b7 100644 --- a/src/tl/tl/tlLog.h +++ b/src/tl/tl/tlLog.h @@ -136,6 +136,7 @@ protected: virtual void endl () = 0; virtual void end () = 0; virtual void begin () = 0; + virtual void yield () = 0; tl::Mutex m_lock; @@ -265,6 +266,7 @@ protected: virtual void endl (); virtual void end (); virtual void begin (); + virtual void yield (); private: tl::weak_collection m_channels; diff --git a/src/tl/tl/tlUnitTest.h b/src/tl/tl/tlUnitTest.h index 8812dae56..91571882e 100644 --- a/src/tl/tl/tlUnitTest.h +++ b/src/tl/tl/tlUnitTest.h @@ -208,6 +208,7 @@ protected: virtual void endl (); virtual void end (); virtual void begin (); + virtual void yield () { } private: std::ostringstream m_text; diff --git a/src/unit_tests/utTestConsole.cc b/src/unit_tests/utTestConsole.cc index b72c7048b..da19a5e60 100644 --- a/src/unit_tests/utTestConsole.cc +++ b/src/unit_tests/utTestConsole.cc @@ -75,6 +75,8 @@ protected: // .. nothing yet .. } + virtual void yield () { } + private: int m_verbosity; }; @@ -108,6 +110,8 @@ protected: { TestConsole::instance ()->begin_warn (); } + + virtual void yield () { } }; class ErrorChannel : public tl::Channel @@ -139,6 +143,8 @@ protected: { TestConsole::instance ()->begin_error (); } + + virtual void yield () { } }; class CtrlChannel : public tl::Channel @@ -180,6 +186,8 @@ protected: } } + virtual void yield () { } + private: bool m_with_xml; };