testcase for runtime loglevels form LRN

3 files changed, 456 insertions, 2 deletions

diff --git a/src/util/Makefile.am b/src/util/Makefile.am
index 02f823442..d816bc42c 100644
--- a/src/util/Makefile.am
+++ b/src/util/Makefile.am
@@ -26,7 +26,8 @@ if USE_COVERAGE
 endif
 
 noinst_PROGRAMS = \
- gnunet-config-diff
+ gnunet-config-diff \
+ test_common_logging_dummy
 
 gnunet_config_diff_SOURCES = \
  gnunet-config-diff.c
@@ -35,6 +36,12 @@ gnunet_config_diff_LDADD = \
 gnunet_config_diff_DEPENDENCIES = \
  libgnunetutil.la
 
+test_common_logging_dummy_SOURCES = \
+ test_common_logging_dummy.c
+test_common_logging_dummy_LDADD = \
+ $(top_builddir)/src/util/libgnunetutil.la
+test_common_logging_dummy_DEPENDENCIES = \
+ libgnunetutil.la
 
 lib_LTLIBRARIES = libgnunetutil.la
 
@@ -175,7 +182,8 @@ check_PROGRAMS = \
  test_strings \
  test_time \
  $(BENCHMARKS) \
- test_os_start_process 
+ test_os_start_process \
+ test_common_logging_runtime_loglevels
 
 if ENABLE_TEST_RUN
 TESTS = $(check_PROGRAMS)
@@ -212,6 +220,11 @@ test_common_logging_SOURCES = \
 test_common_logging_LDADD = \
  $(top_builddir)/src/util/libgnunetutil.la  
 
+test_common_logging_runtime_loglevels_SOURCES = \
+ test_common_logging_runtime_loglevels.c
+test_common_logging_runtime_loglevels_LDADD = \
+ $(top_builddir)/src/util/libgnunetutil.la
+
 test_configuration_SOURCES = \
  test_configuration.c
 test_configuration_LDADD = \
diff --git a/src/util/test_common_logging_dummy.c b/src/util/test_common_logging_dummy.c
new file mode 100644
index 000000000..64d164a13
--- /dev/null
+++ b/src/util/test_common_logging_dummy.c
@@ -0,0 +1,92 @@
+/*
+     This file is part of GNUnet.
+     (C) 2008 Christian Grothoff (and other contributing authors)
+
+     GNUnet is free software; you can redistribute it and/or modify
+     it under the terms of the GNU General Public License as published
+     by the Free Software Foundation; either version 3, or (at your
+     option) any later version.
+
+     GNUnet is distributed in the hope that it will be useful, but
+     WITHOUT ANY WARRANTY; without even the implied warranty of
+     MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the GNU
+     General Public License for more details.
+
+     You should have received a copy of the GNU General Public License
+     along with GNUnet; see the file COPYING.  If not, write to the
+     Free Software Foundation, Inc., 59 Temple Place - Suite 330,
+     Boston, MA 02111-1307, USA.
+*/
+
+/**
+ * @file util/test_common_logging_dummy.c
+ * @brief dummy labrat for the testcase for the logging module (runtime
+ * log level adjustment)
+ * @author LRN
+ */
+#include "platform.h"
+#include "gnunet_common.h"
+#include "gnunet_time_lib.h"
+#include "gnunet_network_lib.h"
+
+#define MS200 GNUNET_TIME_relative_multiply(GNUNET_TIME_UNIT_MILLISECONDS, 200)
+
+static void
+my_log (void *ctx, enum GNUNET_ErrorType kind, const char *component,
+        const char *date, const char *msg)
+{
+  if (strncmp ("test-common-logging-dummy", component, 25) != 0)
+    return;
+  fprintf (stdout, "%s", msg);
+  fflush (stdout);
+}
+
+static int
+expensive_func ()
+{
+  return GNUNET_NETWORK_socket_select (NULL, NULL, NULL, MS200);
+}
+
+#define pr(kind,lvl) {\
+  struct GNUNET_TIME_Absolute t1, t2;\
+  t1 = GNUNET_TIME_absolute_get ();\
+  GNUNET_log (kind, "L%s %d\n", lvl, expensive_func());\
+  t2 = GNUNET_TIME_absolute_get ();\
+  printf ("1%s %llu\n", lvl,\
+          (unsigned long long) GNUNET_TIME_absolute_get_difference (t1, t2).rel_value); \
+}
+
+#define pr2(kind,lvl) {\
+  struct GNUNET_TIME_Absolute t1, t2;\
+  t1 = GNUNET_TIME_absolute_get ();\
+  GNUNET_log (kind, "L%s %d\n", lvl, expensive_func());\
+  t2 = GNUNET_TIME_absolute_get ();\
+  printf ("2%s %llu\n", lvl,\
+          (unsigned long long) GNUNET_TIME_absolute_get_difference (t1, t2).rel_value); \
+}
+
+int
+main (int argc, char *argv[])
+{
+  /* We set up logging with NULL level - will be overrided by
+   * GNUNET_LOG or GNUNET_FORCE_LOG at runtime.
+   */
+  GNUNET_log_setup ("test-common-logging-dummy", NULL, "/dev/null");
+  GNUNET_logger_add (&my_log, NULL);
+  pr (GNUNET_ERROR_TYPE_ERROR, "ERROR");
+  pr (GNUNET_ERROR_TYPE_WARNING, "WARNING");
+  pr (GNUNET_ERROR_TYPE_INFO, "INFO");
+  pr (GNUNET_ERROR_TYPE_DEBUG, "DEBUG");
+
+  /* We set up logging with WARNING level - will onle be overrided by
+   * GNUNET_FORCE_LOG at runtime.
+   */
+  GNUNET_log_setup ("test-common-logging-dummy", "WARNING", "/dev/null");
+  pr2 (GNUNET_ERROR_TYPE_ERROR, "ERROR");
+  pr2 (GNUNET_ERROR_TYPE_WARNING, "WARNING");
+  pr2 (GNUNET_ERROR_TYPE_INFO, "INFO");
+  pr2 (GNUNET_ERROR_TYPE_DEBUG, "DEBUG");
+  return 0;
+} /* end of main */
+
+/* end of test_common_logging_dummy.c */
diff --git a/src/util/test_common_logging_runtime_loglevels.c b/src/util/test_common_logging_runtime_loglevels.c
new file mode 100644
index 000000000..e2864165a
--- /dev/null
+++ b/src/util/test_common_logging_runtime_loglevels.c
@@ -0,0 +1,349 @@
+/*
+     This file is part of GNUnet.
+     (C) 2008 Christian Grothoff (and other contributing authors)
+
+     GNUnet is free software; you can redistribute it and/or modify
+     it under the terms of the GNU General Public License as published
+     by the Free Software Foundation; either version 3, or (at your
+     option) any later version.
+
+     GNUnet is distributed in the hope that it will be useful, but
+     WITHOUT ANY WARRANTY; without even the implied warranty of
+     MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the GNU
+     General Public License for more details.
+
+     You should have received a copy of the GNU General Public License
+     along with GNUnet; see the file COPYING.  If not, write to the
+     Free Software Foundation, Inc., 59 Temple Place - Suite 330,
+     Boston, MA 02111-1307, USA.
+*/
+
+/**
+ * @file util/test_common_logging_runtime_loglevels.c
+ * @brief testcase for the logging module  (runtime log level adjustment)
+ * @author LRN
+ */
+#include "platform.h"
+#include "gnunet_common.h"
+#include "gnunet_scheduler_lib.h"
+#include "gnunet_network_lib.h"
+#include "gnunet_disk_lib.h"
+#include "gnunet_os_lib.h"
+
+#define VERBOSE GNUNET_EXTRA_LOGGING
+
+static int ok;
+static int phase = 0;
+
+static struct GNUNET_OS_Process *proc;
+
+/* Pipe to read from started processes stdout (on read end) */
+static struct GNUNET_DISK_PipeHandle *pipe_stdout;
+
+static GNUNET_SCHEDULER_TaskIdentifier die_task;
+
+static void runone ();
+
+static void
+end_task (void *cls, const struct GNUNET_SCHEDULER_TaskContext *tc)
+{
+
+  if (0 != GNUNET_OS_process_kill (proc, SIGTERM))
+  {
+    GNUNET_log_strerror (GNUNET_ERROR_TYPE_WARNING, "kill");
+  }
+  GNUNET_OS_process_wait (proc);
+  GNUNET_OS_process_close (proc);
+  proc = NULL;
+  GNUNET_DISK_pipe_close (pipe_stdout);
+  if (ok == 1)
+  {
+    if (phase < 9)
+    {
+      phase += 1;
+      runone ();
+    }
+    else
+      ok = 0;
+  }
+  else
+    GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "failing\n");
+}
+
+static char *
+read_output_line (int phase_from1, int phase_to1, int phase_from2,
+                  int phase_to2, char c, char *expect_level,
+                  long delay_morethan, long delay_lessthan, int phase, char *p,
+                  int *len, long *delay, char level[8])
+{
+  char *r = p;
+  char t[7];
+  int i, j, stop = 0;
+  j = 0;
+  int stage = 0;
+  if (!(phase >= phase_from1 && phase <= phase_to1) &&
+     !(phase >= phase_from2 && phase <= phase_to2))
+    return p;
+  GNUNET_log (GNUNET_ERROR_TYPE_DEBUG, "Trying to match '%c%s \\d\\r\\n' on %s", c, expect_level, p);
+  for (i = 0; i < *len && !stop; i++)
+  {
+    switch (stage)
+    {
+    case 0: /* read first char */
+      if (r[i] != c)
+      {
+        GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "Expected '%c', but got '%c'\n", c, r[i]);
+        GNUNET_break (0);
+        return NULL;
+      }
+      stage += 1;
+      break;
+    case 1:  /* read at most 7 char-long error level string, finished by ' ' */
+      if (r[i] == ' ')
+      {
+        level[j] = '\0';
+        stage += 1;
+        j = 0;
+      }
+      else if (i == 8)
+      {
+        GNUNET_break (0);
+        ok = 2;
+        return NULL;
+      }
+      else
+        level[j++] = r[i];
+      break;
+    case 2: /* read the delay, finished by '\n' */
+      t[j++] = r[i];
+#if WINDOWS
+      if (r[i] == '\r' && r[i + 1] == '\n')
+      {
+        i += 1;
+        t[j - 1] = '\0';
+        *delay = strtol (t, NULL, 10);
+        stop = 1;
+      }
+#else
+      if (r[i] == '\n')
+      {
+        t[j - 1] = '\0';
+        *delay = strtol (t, NULL, 10);
+        stop = 1;
+      }
+#endif
+      break;
+    }
+  }
+  if (!stop || strcmp (expect_level, level) != 0 || *delay < 0 || *delay > 1000 ||
+      (!((*delay < delay_lessthan) || !(*delay > delay_morethan)) && c != '1' && c != '2'))
+    return NULL;
+  *len = *len - i;
+  return &r[i];
+}
+
+char buf[20*16];
+char *buf_ptr;
+int bytes;
+
+static void
+read_call (void *cls, const struct GNUNET_SCHEDULER_TaskContext *tc)
+{
+  struct GNUNET_DISK_FileHandle *stdout_read_handle = cls;
+  char level[8];
+  long delay;
+  long delays[8];
+  int rd;
+
+  rd = GNUNET_DISK_file_read (stdout_read_handle, buf_ptr, sizeof (buf) - bytes);
+  if (rd > 0)
+  {
+    buf_ptr += rd;
+    bytes += rd;
+    while (rd > 0)
+    {
+      rd = GNUNET_DISK_file_read (stdout_read_handle, buf_ptr, sizeof (buf) - bytes);
+      if (rd == -1 && errno == EWOULDBLOCK)
+      {
+        GNUNET_SCHEDULER_add_read_file (GNUNET_TIME_UNIT_FOREVER_REL,
+                                        stdout_read_handle, &read_call,
+                                        (void *) stdout_read_handle);
+        return;
+      }
+      else if (rd == -1)
+        rd = 0;
+      buf_ptr += rd;
+      bytes += rd;
+    }
+  }
+
+#if VERBOSE
+  fprintf (stderr, "bytes is %d:%s\n", bytes, buf);
+#endif
+
+  /* +------CHILD OUTPUT--
+   * |      SOFT     HARD
+   * |    E W I D  E W I D
+   * | 0E *        * *
+   * | 1W * *      * *
+   * P 2I * * *    * *
+   * H 3D * * * *  * *
+   * A
+   * S 4E *        *
+   * E 5W * *      * *
+   * | 6I * * *    * * *
+   * | 7D * * * *  * * * *
+   * | 8  * *      * *
+   * | 9  * *      * *
+   */
+  char *p = buf;
+  if (bytes == 20*16 ||
+      !(p = read_output_line (0, 3, 4, 9, 'L', "ERROR", -1, 1, phase, p, &bytes, &delay, level)) ||
+      !(p = read_output_line (0, 3, 4, 9, '1', "ERROR", 200, 400, phase, p, &bytes, &delays[0], level)) ||
+      !(p = read_output_line (1, 3, 5, 9, 'L', "WARNING", -1, 1, phase, p, &bytes, &delay, level)) ||
+      !(p = read_output_line (0, 3, 4, 9, '1', "WARNING", 200, 400, phase, p, &bytes, &delays[1], level)) ||
+      !(p = read_output_line (2, 3, 6, 7, 'L', "INFO", -1, 1, phase, p, &bytes, &delay, level)) ||
+      !(p = read_output_line (0, 3, 4, 9, '1', "INFO", 200, 400, phase, p, &bytes, &delays[2], level)) ||
+      !(p = read_output_line (3, 3, 7, 7, 'L', "DEBUG", -1, 1, phase, p, &bytes, &delay, level)) ||
+      !(p = read_output_line (0, 3, 4, 9, '1', "DEBUG", 200, 400, phase, p, &bytes, &delays[3], level)) ||
+      !(p = read_output_line (0, 3, 4, 9, 'L', "ERROR", -1, 1, phase, p, &bytes, &delay, level)) ||
+      !(p = read_output_line (0, 3, 4, 9, '2', "ERROR", 200, 400, phase, p, &bytes, &delays[4], level)) ||
+      !(p = read_output_line (0, 3, 5, 9, 'L', "WARNING", -1, 1, phase, p, &bytes, &delay, level)) ||
+      !(p = read_output_line (0, 3, 4, 9, '2', "WARNING", 200, 400, phase, p, &bytes, &delays[5], level)) ||
+      !(p = read_output_line (-1, -1, 6, 7, 'L', "INFO", -1, 1, phase, p, &bytes, &delay, level)) ||
+      !(p = read_output_line (0, 3, 4, 9, '2', "INFO", 200, 400, phase, p, &bytes, &delays[6], level)) ||
+      !(p = read_output_line (-1, -1, 7, 7, 'L', "DEBUG", -1, 1, phase, p, &bytes, &delay, level)) ||
+      !(p = read_output_line (0, 3, 4, 9, '2', "DEBUG", 200, 400, phase, p, &bytes, &delays[7], level)))
+  {
+    if (bytes == 20*16)
+      fprintf (stderr, "Ran out of buffer space!\n");
+    GNUNET_break (0);
+    ok = 2;
+    GNUNET_SCHEDULER_cancel (die_task);
+    GNUNET_SCHEDULER_add_now (&end_task, NULL);
+    return;
+  }
+
+  GNUNET_SCHEDULER_cancel (die_task);
+  GNUNET_SCHEDULER_add_now (&end_task, NULL);
+}
+
+static void
+runone ()
+{
+  char *fn;
+  const struct GNUNET_DISK_FileHandle *stdout_read_handle;
+
+  GNUNET_asprintf (&fn, "test_common_logging_dummy");
+
+  pipe_stdout = GNUNET_DISK_pipe (GNUNET_YES, GNUNET_NO, GNUNET_YES);
+
+  if (pipe_stdout == NULL)
+  {
+    GNUNET_break (0);
+    ok = 2;
+    GNUNET_free (fn);
+    return;
+  }
+
+  putenv ("GNUNET_LOG=");
+  putenv ("GNUNET_FORCE_LOG=");
+  switch (phase)
+  {
+  case 0:
+    putenv ("GNUNET_LOG=;;;;ERROR");
+    break;
+  case 1:
+    putenv ("GNUNET_LOG=;;;;WARNING");
+    break;
+  case 2:
+    putenv ("GNUNET_LOG=;;;;INFO");
+    break;
+  case 3:
+    putenv ("GNUNET_LOG=;;;;DEBUG");
+    break;
+  case 4:
+    putenv ("GNUNET_FORCE_LOG=;;;;ERROR");
+    break;
+  case 5:
+    putenv ("GNUNET_FORCE_LOG=;;;;WARNING");
+    break;
+  case 6:
+    putenv ("GNUNET_FORCE_LOG=;;;;INFO");
+    break;
+  case 7:
+    putenv ("GNUNET_FORCE_LOG=;;;;DEBUG");
+    break;
+  case 8:
+    putenv ("GNUNET_LOG=blah;;;;ERROR");
+    break;
+  case 9:
+    putenv ("GNUNET_FORCE_LOG=blah;;;;ERROR");
+    break;
+  }
+
+  proc =
+      GNUNET_OS_start_process (NULL, pipe_stdout, fn,
+                               "test_common_logging_dummy", NULL);
+  GNUNET_free (fn);
+  putenv ("GNUNET_FORCE_LOG=");
+  putenv ("GNUNET_LOG=");
+
+  /* Close the write end of the read pipe */
+  GNUNET_DISK_pipe_close_end (pipe_stdout, GNUNET_DISK_PIPE_END_WRITE);
+
+  stdout_read_handle =
+      GNUNET_DISK_pipe_handle (pipe_stdout, GNUNET_DISK_PIPE_END_READ);
+
+  die_task =
+      GNUNET_SCHEDULER_add_delayed (GNUNET_TIME_relative_multiply
+                                    (GNUNET_TIME_UNIT_SECONDS, 10), &end_task,
+                                    NULL);
+
+  bytes = 0;
+  buf_ptr = buf;
+  memset (&buf, 0, sizeof (buf));
+
+  GNUNET_SCHEDULER_add_read_file (GNUNET_TIME_UNIT_FOREVER_REL,
+                                  stdout_read_handle, &read_call,
+                                  (void *) stdout_read_handle);
+}
+
+static void
+task (void *cls, const struct GNUNET_SCHEDULER_TaskContext *tc)
+{
+  phase = 0;
+  runone ();
+}
+
+/**
+ * Main method, starts scheduler with task1,
+ * checks that "ok" is correct at the end.
+ */
+static int
+check ()
+{
+  ok = 1;
+  GNUNET_SCHEDULER_run (&task, &ok);
+  return ok;
+}
+
+
+int
+main (int argc, char *argv[])
+{
+  int ret;
+
+  GNUNET_log_setup ("test-common-logging-runtime-loglevels",
+#if VERBOSE
+                    "DEBUG",
+#else
+                    "WARNING",
+#endif
+                    NULL);
+  ret = check ();
+
+  return ret;
+}
+
+/* end of test_common_logging_runtime_loglevels.c */