bug 1362:

- don't inline spaced_time_string all the time to save space
- better multithreading handling in case of exceptions and pthread_cancel

LCS/Common/include/Common/LofarLogCout.h

@@ -237,11 +237,47 @@ public: \
 	} while (0)
 
 #if defined USE_THREADS
+// make sure that the logging is 
+//   a) thread safe, using a mutex, which is unlocked even if thread_unsafe_cLog throws
+//   b) does not trigger on a pthread_cancel, because stl will cause an abort() due to
+//      not rethrowing after a catch(...) in ostream::put(char).
+
+// an example crash test will reveal the problem:
+/*
+#include <iostream>
+#include <pthread.h>
+
+void *thread(void*)
+{
+  // ostream::put(char) will do a catch(...), discarding the pthread cancel
+  // "exception", which is fatal.
+  for(;;) std::cout << "crash" << std::endl;
+  return 0;
+}
+
+int main() {
+  pthread_t t;
+  pthread_create( &t, 0, &thread, 0 );
+
+  pthread_cancel( t );
+  pthread_join( t, 0 );
+}
+*/
 #define	cLog(level,levelname,message) \
 	do { \
-		pthread_mutex_lock(&::LOFAR::LFDebug::mutex); \
+                struct D { \
+                   D() { pthread_mutex_lock(&::LOFAR::LFDebug::mutex); \
+                         pthread_setcancelstate( PTHREAD_CANCEL_DISABLE, &oldCancelState ); \
+                       } \
+                  ~D() { \
+                         pthread_setcancelstate( oldCancelState, 0 ); \
+                         pthread_mutex_unlock(&::LOFAR::LFDebug::mutex); \
+                       } \
+                   int oldCancelState; \
+                } pthread_control; \
+                (void)pthread_control; \
+                \
 		thread_unsafe_cLog(level,levelname,message); \
-		pthread_mutex_unlock(&::LOFAR::LFDebug::mutex); \
 	} while(0)
 #else
 #define	cLog(level,levelname,message) \
@@ -384,22 +420,7 @@ namespace LOFAR
     };
 #endif
 
-    // append the current time (including milliseconds) to the provided stream
-    inline std::ostream& spaced_time_string (std::ostream &str)
-    {
-      struct timeval tv;
-      struct tm timeinfo;
-      char timestr[40];
-      const unsigned len = 18; // 18 == strlen( " 01-01-10 10:00:00" )
-
-      gettimeofday(&tv,0);
-      localtime_r(&tv.tv_sec,&timeinfo);
-      strftime( timestr, sizeof timestr, " %d-%m-%y %T", &timeinfo );
-      snprintf( timestr + len, sizeof timestr - len, ".%03d ", static_cast<int>(tv.tv_usec/1000) );
-
-      str << timestr;
-      return str;
-    }
+    std::ostream& spaced_time_string (std::ostream &str);
 
     extern Context DebugContext;
     inline Context & getLFDebugContext ()  { return DebugContext; }

LCS/Common/src/LofarLogCout.cc

@@ -243,6 +243,24 @@ namespace LFDebug
   // }
   // 
 
+    // append the current time (including milliseconds) to the provided stream
+    std::ostream& spaced_time_string (std::ostream &str)
+    {
+      struct timeval tv;
+      struct tm timeinfo;
+      char timestr[40];
+      const unsigned len = 18; // 18 == strlen( " 01-01-10 10:00:00" )
+
+      gettimeofday(&tv,0);
+      localtime_r(&tv.tv_sec,&timeinfo);
+      strftime( timestr, sizeof timestr, " %d-%m-%y %T", &timeinfo );
+      snprintf( timestr + len, sizeof timestr - len, ".%03d ", static_cast<int>(tv.tv_usec/1000) );
+      timestr[sizeof timestr - 1] = 0;
+
+      str << timestr;
+      return str;
+    }
+
   // -----------------------------------------------------------------------
   // ssprintf
   // Like sprintf, but returns an string with the output