src/util/test_common_logging_runtime_loglevels.c

   1 /*
   2      This file is part of GNUnet.
   3      (C) 2008 Christian Grothoff (and other contributing authors)
   4
   5      GNUnet is free software; you can redistribute it and/or modify
   6      it under the terms of the GNU General Public License as published
   7      by the Free Software Foundation; either version 3, or (at your
   8      option) any later version.
   9
  10      GNUnet is distributed in the hope that it will be useful, but
  11      WITHOUT ANY WARRANTY; without even the implied warranty of
  12      MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the GNU
  13      General Public License for more details.
  14
  15      You should have received a copy of the GNU General Public License
  16      along with GNUnet; see the file COPYING.  If not, write to the
  17      Free Software Foundation, Inc., 59 Temple Place - Suite 330,
  18      Boston, MA 02111-1307, USA.
  19 */
  20
  21 /**
  22  * @file util/test_common_logging_runtime_loglevels.c
  23  * @brief testcase for the logging module  (runtime log level adjustment)
  24  * @author LRN
  25  */
  26 #include "platform.h"
  27 #include "gnunet_common.h"
  28 #include "gnunet_scheduler_lib.h"
  29 #include "gnunet_network_lib.h"
  30 #include "gnunet_disk_lib.h"
  31 #include "gnunet_os_lib.h"
  32
  33 #define VERBOSE GNUNET_EXTRA_LOGGING
  34
  35 static int ok;
  36 static int phase = 0;
  37
  38 static struct GNUNET_OS_Process *proc;
  39
  40 /* Pipe to read from started processes stdout (on read end) */
  41 static struct GNUNET_DISK_PipeHandle *pipe_stdout;
  42
  43 static GNUNET_SCHEDULER_TaskIdentifier die_task;
  44
  45 static void runone ();
  46
  47 static void
  48 end_task (void *cls, const struct GNUNET_SCHEDULER_TaskContext *tc)
  49 {
  50
  51   if (0 != GNUNET_OS_process_kill (proc, SIGTERM))
  52   {
  53     GNUNET_log_strerror (GNUNET_ERROR_TYPE_WARNING, "kill");
  54   }
  55   GNUNET_OS_process_wait (proc);
  56   GNUNET_OS_process_close (proc);
  57   proc = NULL;
  58   GNUNET_DISK_pipe_close (pipe_stdout);
  59   if (ok == 1)
  60   {
  61     if (phase < 9)
  62     {
  63       phase += 1;
  64       runone ();
  65     }
  66     else
  67       ok = 0;
  68   }
  69   else
  70     GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "failing\n");
  71 }
  72
  73 static char *
  74 read_output_line (int phase_from1, int phase_to1, int phase_from2,
  75                   int phase_to2, char c, char *expect_level,
  76                   long delay_morethan, long delay_lessthan, int phase, char *p,
  77                   int *len, long *delay, char level[8])
  78 {
  79   char *r = p;
  80   char t[7];
  81   int i, j, stop = 0;
  82   j = 0;
  83   int stage = 0;
  84   if (!(phase >= phase_from1 && phase <= phase_to1) &&
  85      !(phase >= phase_from2 && phase <= phase_to2))
  86     return p;
  87   GNUNET_log (GNUNET_ERROR_TYPE_DEBUG, "Trying to match '%c%s \\d\\r\\n' on %s", c, expect_level, p);
  88   for (i = 0; i < *len && !stop; i++)
  89   {
  90     switch (stage)
  91     {
  92     case 0: /* read first char */
  93       if (r[i] != c)
  94       {
  95         GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "Expected '%c', but got '%c'\n", c, r[i]);
  96         GNUNET_break (0);
  97         return NULL;
  98       }
  99       stage += 1;
 100       break;
 101     case 1:  /* read at most 7 char-long error level string, finished by ' ' */
 102       if (r[i] == ' ')
 103       {
 104         level[j] = '\0';
 105         stage += 1;
 106         j = 0;
 107       }
 108       else if (i == 8)
 109       {
 110         GNUNET_break (0);
 111         ok = 2;
 112         return NULL;
 113       }
 114       else
 115         level[j++] = r[i];
 116       break;
 117     case 2: /* read the delay, finished by '\n' */
 118       t[j++] = r[i];
 119 #if WINDOWS
 120       if (r[i] == '\r' && r[i + 1] == '\n')
 121       {
 122         i += 1;
 123         t[j - 1] = '\0';
 124         *delay = strtol (t, NULL, 10);
 125         stop = 1;
 126       }
 127 #else
 128       if (r[i] == '\n')
 129       {
 130         t[j - 1] = '\0';
 131         *delay = strtol (t, NULL, 10);
 132         stop = 1;
 133       }
 134 #endif
 135       break;
 136     }
 137   }
 138   if (!stop || strcmp (expect_level, level) != 0 || *delay < 0 || *delay > 1000 ||
 139       (!((*delay < delay_lessthan) || !(*delay > delay_morethan)) && c != '1' && c != '2'))
 140     return NULL;
 141   *len = *len - i;
 142   return &r[i];
 143 }
 144
 145 char buf[20*16];
 146 char *buf_ptr;
 147 int bytes;
 148
 149 static void
 150 read_call (void *cls, const struct GNUNET_SCHEDULER_TaskContext *tc)
 151 {
 152   struct GNUNET_DISK_FileHandle *stdout_read_handle = cls;
 153   char level[8];
 154   long delay;
 155   long delays[8];
 156   int rd;
 157
 158   rd = GNUNET_DISK_file_read (stdout_read_handle, buf_ptr, sizeof (buf) - bytes);
 159   if (rd > 0)
 160   {
 161     buf_ptr += rd;
 162     bytes += rd;
 163     while (rd > 0)
 164     {
 165       rd = GNUNET_DISK_file_read (stdout_read_handle, buf_ptr, sizeof (buf) - bytes);
 166       if (rd == -1 && errno == EWOULDBLOCK)
 167       {
 168         GNUNET_SCHEDULER_add_read_file (GNUNET_TIME_UNIT_FOREVER_REL,
 169                                         stdout_read_handle, &read_call,
 170                                         (void *) stdout_read_handle);
 171         return;
 172       }
 173       else if (rd == -1)
 174         rd = 0;
 175       buf_ptr += rd;
 176       bytes += rd;
 177     }
 178   }
 179
 180 #if VERBOSE
 181   fprintf (stderr, "bytes is %d:%s\n", bytes, buf);
 182 #endif
 183
 184   /* +------CHILD OUTPUT--
 185    * |      SOFT     HARD
 186    * |    E W I D  E W I D
 187    * | 0E *        * *
 188    * | 1W * *      * *
 189    * P 2I * * *    * *
 190    * H 3D * * * *  * *
 191    * A
 192    * S 4E *        *
 193    * E 5W * *      * *
 194    * | 6I * * *    * * *
 195    * | 7D * * * *  * * * *
 196    * | 8  * *      * *
 197    * | 9  * *      * *
 198    */
 199   char *p = buf;
 200   if (bytes == 20*16 ||
 201       !(p = read_output_line (0, 3, 4, 9, 'L', "ERROR", -1, 1, phase, p, &bytes, &delay, level)) ||
 202       !(p = read_output_line (0, 3, 4, 9, '1', "ERROR", 200, 400, phase, p, &bytes, &delays[0], level)) ||
 203       !(p = read_output_line (1, 3, 5, 9, 'L', "WARNING", -1, 1, phase, p, &bytes, &delay, level)) ||
 204       !(p = read_output_line (0, 3, 4, 9, '1', "WARNING", 200, 400, phase, p, &bytes, &delays[1], level)) ||
 205       !(p = read_output_line (2, 3, 6, 7, 'L', "INFO", -1, 1, phase, p, &bytes, &delay, level)) ||
 206       !(p = read_output_line (0, 3, 4, 9, '1', "INFO", 200, 400, phase, p, &bytes, &delays[2], level)) ||
 207       !(p = read_output_line (3, 3, 7, 7, 'L', "DEBUG", -1, 1, phase, p, &bytes, &delay, level)) ||
 208       !(p = read_output_line (0, 3, 4, 9, '1', "DEBUG", 200, 400, phase, p, &bytes, &delays[3], level)) ||
 209       !(p = read_output_line (0, 3, 4, 9, 'L', "ERROR", -1, 1, phase, p, &bytes, &delay, level)) ||
 210       !(p = read_output_line (0, 3, 4, 9, '2', "ERROR", 200, 400, phase, p, &bytes, &delays[4], level)) ||
 211       !(p = read_output_line (0, 3, 5, 9, 'L', "WARNING", -1, 1, phase, p, &bytes, &delay, level)) ||
 212       !(p = read_output_line (0, 3, 4, 9, '2', "WARNING", 200, 400, phase, p, &bytes, &delays[5], level)) ||
 213       !(p = read_output_line (-1, -1, 6, 7, 'L', "INFO", -1, 1, phase, p, &bytes, &delay, level)) ||
 214       !(p = read_output_line (0, 3, 4, 9, '2', "INFO", 200, 400, phase, p, &bytes, &delays[6], level)) ||
 215       !(p = read_output_line (-1, -1, 7, 7, 'L', "DEBUG", -1, 1, phase, p, &bytes, &delay, level)) ||
 216       !(p = read_output_line (0, 3, 4, 9, '2', "DEBUG", 200, 400, phase, p, &bytes, &delays[7], level)))
 217   {
 218     if (bytes == 20*16)
 219       fprintf (stderr, "Ran out of buffer space!\n");
 220     GNUNET_break (0);
 221     ok = 2;
 222     GNUNET_SCHEDULER_cancel (die_task);
 223     GNUNET_SCHEDULER_add_now (&end_task, NULL);
 224     return;
 225   }
 226
 227   GNUNET_SCHEDULER_cancel (die_task);
 228   GNUNET_SCHEDULER_add_now (&end_task, NULL);
 229 }
 230
 231 static void
 232 runone ()
 233 {
 234   char *fn;
 235   const struct GNUNET_DISK_FileHandle *stdout_read_handle;
 236
 237   GNUNET_asprintf (&fn, "test_common_logging_dummy");
 238
 239   pipe_stdout = GNUNET_DISK_pipe (GNUNET_YES, GNUNET_NO, GNUNET_YES);
 240
 241   if (pipe_stdout == NULL)
 242   {
 243     GNUNET_break (0);
 244     ok = 2;
 245     GNUNET_free (fn);
 246     return;
 247   }
 248
 249   putenv ("GNUNET_LOG=");
 250   putenv ("GNUNET_FORCE_LOG=");
 251   switch (phase)
 252   {
 253   case 0:
 254     putenv ("GNUNET_LOG=;;;;ERROR");
 255     break;
 256   case 1:
 257     putenv ("GNUNET_LOG=;;;;WARNING");
 258     break;
 259   case 2:
 260     putenv ("GNUNET_LOG=;;;;INFO");
 261     break;
 262   case 3:
 263     putenv ("GNUNET_LOG=;;;;DEBUG");
 264     break;
 265   case 4:
 266     putenv ("GNUNET_FORCE_LOG=;;;;ERROR");
 267     break;
 268   case 5:
 269     putenv ("GNUNET_FORCE_LOG=;;;;WARNING");
 270     break;
 271   case 6:
 272     putenv ("GNUNET_FORCE_LOG=;;;;INFO");
 273     break;
 274   case 7:
 275     putenv ("GNUNET_FORCE_LOG=;;;;DEBUG");
 276     break;
 277   case 8:
 278     putenv ("GNUNET_LOG=blah;;;;ERROR");
 279     break;
 280   case 9:
 281     putenv ("GNUNET_FORCE_LOG=blah;;;;ERROR");
 282     break;
 283   }
 284
 285   proc =
 286       GNUNET_OS_start_process (NULL, pipe_stdout, fn,
 287                                "test_common_logging_dummy", NULL);
 288   GNUNET_free (fn);
 289   putenv ("GNUNET_FORCE_LOG=");
 290   putenv ("GNUNET_LOG=");
 291
 292   /* Close the write end of the read pipe */
 293   GNUNET_DISK_pipe_close_end (pipe_stdout, GNUNET_DISK_PIPE_END_WRITE);
 294
 295   stdout_read_handle =
 296       GNUNET_DISK_pipe_handle (pipe_stdout, GNUNET_DISK_PIPE_END_READ);
 297
 298   die_task =
 299       GNUNET_SCHEDULER_add_delayed (GNUNET_TIME_relative_multiply
 300                                     (GNUNET_TIME_UNIT_SECONDS, 10), &end_task,
 301                                     NULL);
 302
 303   bytes = 0;
 304   buf_ptr = buf;
 305   memset (&buf, 0, sizeof (buf));
 306
 307   GNUNET_SCHEDULER_add_read_file (GNUNET_TIME_UNIT_FOREVER_REL,
 308                                   stdout_read_handle, &read_call,
 309                                   (void *) stdout_read_handle);
 310 }
 311
 312 static void
 313 task (void *cls, const struct GNUNET_SCHEDULER_TaskContext *tc)
 314 {
 315   phase = 0;
 316   runone ();
 317 }
 318
 319 /**
 320  * Main method, starts scheduler with task1,
 321  * checks that "ok" is correct at the end.
 322  */
 323 static int
 324 check ()
 325 {
 326   ok = 1;
 327   GNUNET_SCHEDULER_run (&task, &ok);
 328   return ok;
 329 }
 330
 331
 332 int
 333 main (int argc, char *argv[])
 334 {
 335   int ret;
 336
 337   GNUNET_log_setup ("test-common-logging-runtime-loglevels",
 338 #if VERBOSE
 339                     "DEBUG",
 340 #else
 341                     "WARNING",
 342 #endif
 343                     NULL);
 344   ret = check ();
 345
 346   return ret;
 347 }
 348
 349 /* end of test_common_logging_runtime_loglevels.c */