nxcomp: add basic logging_test utility in test subdirectory.

Needs more sophisticated features to actually test stuff correctly.

6 files changed, 373 insertions, 1 deletions

diff --git a/nxcomp/.gitignore b/nxcomp/.gitignore
index 019202342..1d00b755b 100644
--- a/nxcomp/.gitignore
+++ b/nxcomp/.gitignore
@@ -19,3 +19,7 @@ m4/lt~obsolete.m4
 nxcomp.pc
 src/Makefile
 src/Makefile.in
+test/.deps/
+test/Makefile
+test/Makefile.in
+test/logging_test
diff --git a/nxcomp/Makefile.am b/nxcomp/Makefile.am
index ae5991c3d..c1f6226bc 100644
--- a/nxcomp/Makefile.am
+++ b/nxcomp/Makefile.am
@@ -1,4 +1,4 @@
-SUBDIRS = src
+SUBDIRS = src test
 
 pkgconfig_DATA = nxcomp.pc
 
diff --git a/nxcomp/configure.ac b/nxcomp/configure.ac
index a61db32c1..3ae81f0d1 100644
--- a/nxcomp/configure.ac
+++ b/nxcomp/configure.ac
@@ -108,6 +108,7 @@ AC_ARG_ENABLE([valgrind],
 AC_CONFIG_FILES([
 Makefile
 src/Makefile
+test/Makefile
 nxcomp.pc
 ])
 
diff --git a/nxcomp/test/Makefile.am b/nxcomp/test/Makefile.am
new file mode 100644
index 000000000..412b8ea94
--- /dev/null
+++ b/nxcomp/test/Makefile.am
@@ -0,0 +1,22 @@
+NULL =
+
+noinst_PROGRAMS = logging_test
+EXTRA_DIST = logging_test
+
+AM_CPPFLAGS = -I$(top_srcdir)/src
+AM_CXXFLAGS =		\
+  @PTHREAD_CFLAGS@	\
+  $(NULL)
+
+logging_test_SOURCES = logging_test.cpp
+logging_test_LDADD =			\
+    $(top_srcdir)/src/.libs/libXcomp.a	\
+    @PTHREAD_LIBS@			\
+    $(NULL)
+
+logging_test_LDFLAGS =	\
+    $(PTHREAD_LDFLAGS)	\
+    $(NULL)
+
+check: all
+	./logging_test
diff --git a/nxcomp/test/logging_test.cpp b/nxcomp/test/logging_test.cpp
new file mode 100644
index 000000000..7e2d7d213
--- /dev/null
+++ b/nxcomp/test/logging_test.cpp
@@ -0,0 +1,224 @@
+#include <cstddef>
+#include <pthread.h>
+#include <signal.h>
+#include <stdlib.h>
+#include <unistd.h>
+#include <errno.h>
+#include <cstdlib>
+#include <ctime>
+#include <climits>
+#include <vector>
+#include <cstring>
+
+#include "logging_test.h"
+
+Faulty_Logger faulty_logger;
+NXLog good_logger;
+
+void print_sigmask () {
+  sigset_t orig_mask;
+  sigemptyset (&orig_mask);
+
+  pthread_sigmask (SIG_SETMASK, NULL, &orig_mask);
+
+  bool empty = true;
+  for (std::size_t i = 0; i < NSIG; ++i) {
+    if (sigismember (&orig_mask, i)) {
+      nxdbg_good << "Signal i (" << i << ") in signal mask." << std::endl;
+      empty = false;
+    }
+  }
+
+  if (empty) {
+    nxdbg_good << "Signal mask empty.";
+  }
+}
+
+void* log_task (void* /* unused */) {
+  /* print_sigmask (); */
+
+  for (std::size_t i = 0; i < 10; ++i) {
+    nxinfo << "Log message " << i << std::endl;
+  }
+}
+
+void sig_handler (int signo) {
+  nxinfo << "Received signal " << signo << std::endl;
+}
+
+void setup_faulty_logger () {
+  faulty_logger.log_level (true);
+  faulty_logger.log_unix_time (false);
+  faulty_logger.log_time (true);
+  faulty_logger.log_location (true);
+  faulty_logger.log_thread_id (true);
+  faulty_logger.level (NXDEBUG);
+}
+
+void setup_good_logger () {
+  good_logger.log_level (true);
+  good_logger.log_unix_time (false);
+  good_logger.log_time (true);
+  good_logger.log_location (true);
+  good_logger.log_thread_id (true);
+  good_logger.level (NXDEBUG);
+}
+
+pthread_t spawn_thread () {
+  pthread_t thread_id;
+  int pthread_ret;
+
+  sigset_t block_mask, orig_mask;
+  sigemptyset (&orig_mask);
+  sigfillset (&block_mask);
+
+  pthread_sigmask (SIG_BLOCK, &block_mask, &orig_mask);
+
+  pthread_ret = pthread_create (&thread_id, NULL, log_task, NULL);
+
+  pthread_sigmask (SIG_SETMASK, &orig_mask, NULL);
+
+  return (thread_id);
+}
+
+void install_signal_handler () {
+  struct sigaction sa;
+  sa.sa_handler = sig_handler;
+  sigemptyset (&sa.sa_mask);
+  sa.sa_flags = SA_RESTART;
+
+  if (-1 == sigaction (SIGUSR1, &sa, NULL)) {
+    nxerr_good << "Unable to install signal handler!" << std::endl;
+  }
+  else {
+    nxdbg_good << "Signal handler registered successfully for SIGUSR1." << std::endl;
+  }
+}
+
+void killing_process_work (pid_t parent_pid) {
+  /* Seed PRNG. */
+  std::srand (std::time (0));
+
+  for (std::size_t i = 0; i < 25; ++i) {
+    /* Sleep for 4 seconds + some random number up to a second. */
+    std::size_t rand_add = (std::rand () % 1000000);
+    usleep (4000000 + rand_add);
+
+    /* Send SIGUSR1 to parent process. */
+    nxdbg_good << "Sending SIGUSR1 (" << SIGUSR1 << ") to parent_pid (" << parent_pid << ")" << std::endl;
+
+    if (kill (parent_pid, SIGUSR1)) {
+      int saved_errno = errno;
+      nxerr_good << "Failed to deliver signal to parent, aborting." << std::endl;
+      nxerr_good << "Error " << saved_errno << ": " << strerror (saved_errno) << std::endl;
+      exit (EXIT_FAILURE);
+    }
+  }
+
+  exit (EXIT_SUCCESS);
+}
+
+void killing_process_init (int argc, char **argv) {
+  /* We're in the "killing process". */
+  pid_t parent_pid = getppid ();
+
+  setup_good_logger ();
+
+  for (std::size_t i = 0; i < argc; ++i) {
+    nxdbg_good << "argv[" << i << "]: " << argv[i] << std::endl;
+  }
+
+  char *end = NULL;
+
+  errno = 0;
+  long parent_pid_check = std::strtol (argv[1], &end, 0);
+
+  if ((errno == ERANGE) && (parent_pid_check == LONG_MAX)) {
+    /* Overflow, handle gracefully. */
+    parent_pid_check = 1;
+  }
+
+  if ((errno == ERANGE) && (parent_pid_check == LONG_MIN)) {
+    /* Underflow, handle gracefully. */
+    parent_pid_check = 1;
+  }
+
+  if (*end) {
+    /* Conversion error (for inputs like "<number>X", end will point to X.) */
+    parent_pid_check = 1;
+  }
+
+  if (parent_pid != parent_pid_check) {
+    nxinfo_good << "Parent PID verification via first argument failed, trusting getppid ()." << std::endl;
+  }
+
+  killing_process_work (parent_pid);
+}
+
+int main (int argc, char **argv) {
+  if (argc > 1) {
+    killing_process_init (argc, argv);
+  }
+  else {
+    /* That's the main process. */
+
+    /* First, fork and create the "killing process". */
+    pid_t pid = fork ();
+
+    if (0 == pid) {
+      /* Child process. */
+      pid_t parent_pid = getppid ();
+
+      /* Prepare to pass-through parent PID. */
+      std::stringstream ss;
+      ss << parent_pid;
+
+      std::vector<std::string> new_argv;
+      new_argv.push_back (std::string (argv[0]));
+      new_argv.push_back (ss.str ());
+
+      std::vector<char *> new_argv_c_str;
+      for (std::vector<std::string>::iterator it = new_argv.begin (); it != new_argv.end (); ++it) {
+        const char *elem = (*it).c_str ();
+        new_argv_c_str.push_back (strndup (elem, std::strlen (elem)));
+      }
+
+      /* Add null pointer as last element. */
+      new_argv_c_str.push_back (0);
+
+      /* Relaunch, with argv[1] containing the ppid. */
+      if (0 != execvp (new_argv_c_str.front (), &(new_argv_c_str.front ()))) {
+        const int saved_errno = errno;
+        std::cerr << "Failed to start \"killing process\"! Panic!" << std::endl;
+        std::cerr << "System error: " << std::strerror (saved_errno) << std::endl;
+        exit (EXIT_FAILURE);
+      }
+    }
+    else if (0 > pid) {
+      const int saved_errno = errno;
+      std::cerr << "Error while forking main process! Panic!" << std::endl;
+      std::cerr << "System error: " << std::strerror (saved_errno) << std::endl;
+      exit (EXIT_FAILURE);
+    }
+    else {
+      /* Main process. */
+      /* Falls through to general code below. */
+    }
+  }
+
+  setup_faulty_logger ();
+
+  pthread_t thread_id = spawn_thread ();
+
+  setup_good_logger ();
+
+  install_signal_handler ();
+
+  /* print_sigmask (); */
+
+  log_task (NULL);
+
+  pthread_join (thread_id, NULL);
+
+  exit (EXIT_SUCCESS);
+}
diff --git a/nxcomp/test/logging_test.h b/nxcomp/test/logging_test.h
new file mode 100644
index 000000000..239fbfe2b
--- /dev/null
+++ b/nxcomp/test/logging_test.h
@@ -0,0 +1,121 @@
+#ifndef LOGGING_TEST_H
+#define LOGGING_TEST_H
+
+#include <unistd.h>
+
+#define INTERNAL_LOGGING_TEST
+#include "Log.h"
+
+class Faulty_Logger : public NXLog {
+    /* Copied from base class, inserted "fault" within critical section. */
+    using NXLog::flush;
+    void flush(per_thread_data *pdt)
+    {
+        sigset_t orig_signal_mask,
+                 tmp_signal_mask;
+        sigemptyset(&orig_signal_mask);
+
+        sigfillset(&tmp_signal_mask);
+
+        pthread_sigmask(SIG_BLOCK, &tmp_signal_mask, &orig_signal_mask);
+
+        if (!pdt->buffer.empty ()) {
+            const std::string str = pdt->buffer.top()->str();
+
+            if (!str.empty())
+            {
+                pthread_mutex_lock(&output_lock_);
+                usleep (3000000);
+                (*stream()) << str;
+                pthread_mutex_unlock(&output_lock_);
+            }
+
+            pdt->buffer.pop();
+        }
+
+        pthread_sigmask(SIG_SETMASK, &orig_signal_mask, NULL);
+    }
+
+    template<typename T>
+    friend Faulty_Logger& operator<<(Faulty_Logger& out, const T& value);
+
+    friend Faulty_Logger& operator<< (Faulty_Logger& out, const NXLogStamp& value);
+};
+
+template <typename T>
+Faulty_Logger& operator<<(Faulty_Logger& out, const T& value) {
+  if ( out.will_log() ) {
+    if ( out.synchronized() ) {
+      // In synchronized mode, we buffer data until a newline, std::flush, or the buffer
+      // gets full. Then we dump the whole thing at once to the output stream, synchronizing
+      // with a mutex.
+      Faulty_Logger::per_thread_data *pdt = out.get_data();
+      assert (!pdt->buffer.empty ());
+      usleep (1000000);
+      (*pdt->buffer.top()) << value;
+
+      if ( ss_length(pdt->buffer.top()) >= out.thread_buffer_size_ || has_newline(value) )
+          out.flush();
+    }
+    else {
+        // In async mode we just dump data on the output stream as-is.
+        // Multithreaded code will have ugly output.
+        *(out.stream()) << value;
+    }
+  }
+
+  return out;
+}
+
+Faulty_Logger& operator<< (Faulty_Logger& out, const NXLogStamp& value)
+{
+    out.current_level( value.level() );
+    out.current_file( value.file() );
+
+    // Writing an NXLogStamp to the stream indicates the start of a new entry.
+    // If there's any content in the buffer, create a new entry in the output
+    // queue.
+    if ( out.synchronized() )
+        out.new_stack_entry();
+
+    out << out.stamp_to_string(value);
+
+    return out;
+}
+
+#undef nxdbg
+#undef nxinfo
+#undef nxwarn
+#undef nxerr
+#undef nxfatal
+
+#define nxdbg    faulty_logger << nxstamp(NXDEBUG)
+#define nxinfo   faulty_logger << nxstamp(NXINFO)
+#define nxwarn   faulty_logger << nxstamp(NXWARNING)
+#define nxerr    faulty_logger << nxstamp(NXERROR)
+#define nxfatal  faulty_logger << nxstamp(NXFATAL)
+
+#define nxdbg_good    good_logger << nxstamp(NXDEBUG)
+#define nxinfo_good   good_logger << nxstamp(NXINFO)
+#define nxwarn_good   good_logger << nxstamp(NXWARNING)
+#define nxerr_good    good_logger << nxstamp(NXERROR)
+#define nxfatal_good  good_logger << nxstamp(NXFATAL)
+
+/* Helper functions used by all component. */
+void print_sigmask ();
+void setup_faulty_logger ();
+void setup_good_logger ();
+
+/* Functions used by both main and auxiliary threads. */
+void* log_task (void* /* unused */);
+
+/* Functions used in main thread only. */
+pthread_t spawn_thread ();
+void install_signal_handler ();
+void sig_handler (int signo);
+
+/* Functions used by "killing" process. */
+void killing_process_init (int argc, char **argv);
+void killing_process_work (pid_t parent_pid);
+
+#endif /* !defined (LOGGING_TEST_H) */