Avoid a deadlock in the logger system

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);
   }

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
    *

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;

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<tl::Channel>::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;

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<tl::Channel> m_channels;

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;

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;
 };