src/util/test_common_logging_runtime_loglevels.c

   1 /*
   2      This file is part of GNUnet.
   3      (C) 2011 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
  46 runone ();
  47
  48 static void
  49 end_task (void *cls, const struct GNUNET_SCHEDULER_TaskContext *tc)
  50 {
  51   GNUNET_log (GNUNET_ERROR_TYPE_DEBUG, "Ending phase %d, ok is %d\n", phase,
  52               ok);
  53   if (0 != GNUNET_OS_process_kill (proc, SIGTERM))
  54   {
  55     GNUNET_log_strerror (GNUNET_ERROR_TYPE_WARNING, "kill");
  56   }
  57   GNUNET_OS_process_wait (proc);
  58   GNUNET_OS_process_close (proc);
  59   proc = NULL;
  60   GNUNET_DISK_pipe_close (pipe_stdout);
  61   if (ok == 1)
  62   {
  63     if (phase < 9)
  64     {
  65       phase += 1;
  66       runone ();
  67     }
  68     else
  69       ok = 0;
  70   }
  71   else
  72     GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "failing\n");
  73 }
  74
  75 static char *
  76 read_output_line (int phase_from1, int phase_to1, int phase_from2,
  77                   int phase_to2, char c, char *expect_level,
  78                   long delay_morethan, long delay_lessthan, int phase, char *p,
  79                   int *len, long *delay, char level[8])
  80 {
  81   char *r = p;
  82   char t[7];
  83   int i, j, stop = 0;
  84
  85   j = 0;
  86   int stage = 0;
  87
  88   if (!(phase >= phase_from1 && phase <= phase_to1) &&
  89       !(phase >= phase_from2 && phase <= phase_to2))
  90     return p;
  91 #if 0
  92   GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
  93               "Trying to match '%c%s \\d\\r\\n' on %s\n", c, expect_level, p);
  94 #endif
  95   for (i = 0; i < *len && !stop; i++)
  96   {
  97     switch (stage)
  98     {
  99     case 0:                    /* read first char */
 100       if (r[i] != c)
 101       {
 102         GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "Expected '%c', but got '%c'\n", c,
 103                     r[i]);
 104         GNUNET_break (0);
 105         return NULL;
 106       }
 107       stage += 1;
 108       break;
 109     case 1:                    /* read at most 7 char-long error level string, finished by ' ' */
 110       if (r[i] == ' ')
 111       {
 112         level[j] = '\0';
 113         stage += 1;
 114         j = 0;
 115       }
 116       else if (i == 8)
 117       {
 118         GNUNET_break (0);
 119         ok = 2;
 120         return NULL;
 121       }
 122       else
 123         level[j++] = r[i];
 124       break;
 125     case 2:                    /* read the delay, finished by '\n' */
 126       t[j++] = r[i];
 127 #if WINDOWS
 128       if (r[i] == '\r' && r[i + 1] == '\n')
 129       {
 130         i += 1;
 131         t[j - 1] = '\0';
 132         *delay = strtol (t, NULL, 10);
 133         stop = 1;
 134       }
 135 #else
 136       if (r[i] == '\n')
 137       {
 138         t[j - 1] = '\0';
 139         *delay = strtol (t, NULL, 10);
 140         stop = 1;
 141       }
 142 #endif
 143       break;
 144     }
 145   }
 146   if (!stop || strcmp (expect_level, level) != 0 || *delay < 0 || *delay > 1000
 147       || (!((*delay < delay_lessthan) || !(*delay > delay_morethan)) && c != '1'
 148           && c != '2'))
 149     return NULL;
 150   *len = *len - i;
 151   return &r[i];
 152 }
 153
 154 char buf[20 * 16];
 155 char *buf_ptr;
 156 int bytes;
 157
 158 static void
 159 read_call (void *cls, const struct GNUNET_SCHEDULER_TaskContext *tc)
 160 {
 161   struct GNUNET_DISK_FileHandle *stdout_read_handle = cls;
 162   char level[8];
 163   long delay;
 164   long delays[8];
 165   int rd;
 166
 167   rd = GNUNET_DISK_file_read (stdout_read_handle, buf_ptr,
 168                               sizeof (buf) - bytes);
 169   if (rd > 0)
 170   {
 171     buf_ptr += rd;
 172     bytes += rd;
 173 #if VERBOSE
 174     fprintf (stderr, "got %d bytes, reading more\n", rd);
 175 #endif
 176     GNUNET_SCHEDULER_add_read_file (GNUNET_TIME_UNIT_FOREVER_REL,
 177                                     stdout_read_handle, &read_call,
 178                                     (void *) stdout_read_handle);
 179     return;
 180   }
 181
 182 #if VERBOSE
 183   fprintf (stderr, "bytes is %d:%s\n", bytes, buf);
 184 #endif
 185
 186   /* +------CHILD OUTPUT--
 187    * |      SOFT     HARD
 188    * |    E W I D  E W I D
 189    * | 0E *        * *
 190    * | 1W * *      * *
 191    * P 2I * * *    * *
 192    * H 3D * * * *  * *
 193    * A
 194    * S 4E *        *
 195    * E 5W * *      * *
 196    * | 6I * * *    * * *
 197    * | 7D * * * *  * * * *
 198    * | 8  * *      * *
 199    * | 9  * *      * *
 200    */
 201   char *p = buf;
 202
 203   if (bytes == 20 * 16 ||
 204       !(p =
 205         read_output_line (0, 3, 4, 9, 'L', "ERROR", -1, 1, phase, p, &bytes,
 206                           &delay, level)) ||
 207       !(p =
 208         read_output_line (0, 3, 4, 9, '1', "ERROR", 200, 400, phase, p, &bytes,
 209                           &delays[0], level)) ||
 210       !(p =
 211         read_output_line (1, 3, 5, 9, 'L', "WARNING", -1, 1, phase, p, &bytes,
 212                           &delay, level)) ||
 213       !(p =
 214         read_output_line (0, 3, 4, 9, '1', "WARNING", 200, 400, phase, p,
 215                           &bytes, &delays[1], level)) ||
 216       !(p =
 217         read_output_line (2, 3, 6, 7, 'L', "INFO", -1, 1, phase, p, &bytes,
 218                           &delay, level)) ||
 219       !(p =
 220         read_output_line (0, 3, 4, 9, '1', "INFO", 200, 400, phase, p, &bytes,
 221                           &delays[2], level)) ||
 222       !(p =
 223         read_output_line (3, 3, 7, 7, 'L', "DEBUG", -1, 1, phase, p, &bytes,
 224                           &delay, level)) ||
 225       !(p =
 226         read_output_line (0, 3, 4, 9, '1', "DEBUG", 200, 400, phase, p, &bytes,
 227                           &delays[3], level)) ||
 228       !(p =
 229         read_output_line (0, 3, 4, 9, 'L', "ERROR", -1, 1, phase, p, &bytes,
 230                           &delay, level)) ||
 231       !(p =
 232         read_output_line (0, 3, 4, 9, '2', "ERROR", 200, 400, phase, p, &bytes,
 233                           &delays[4], level)) ||
 234       !(p =
 235         read_output_line (0, 3, 5, 9, 'L', "WARNING", -1, 1, phase, p, &bytes,
 236                           &delay, level)) ||
 237       !(p =
 238         read_output_line (0, 3, 4, 9, '2', "WARNING", 200, 400, phase, p,
 239                           &bytes, &delays[5], level)) ||
 240       !(p =
 241         read_output_line (-1, -1, 6, 7, 'L', "INFO", -1, 1, phase, p, &bytes,
 242                           &delay, level)) ||
 243       !(p =
 244         read_output_line (0, 3, 4, 9, '2', "INFO", 200, 400, phase, p, &bytes,
 245                           &delays[6], level)) ||
 246       !(p =
 247         read_output_line (-1, -1, 7, 7, 'L', "DEBUG", -1, 1, phase, p, &bytes,
 248                           &delay, level)) ||
 249       !(p =
 250         read_output_line (0, 3, 4, 9, '2', "DEBUG", 200, 400, phase, p, &bytes,
 251                           &delays[7], level)))
 252   {
 253     if (bytes == 20 * 16)
 254       fprintf (stderr, "Ran out of buffer space!\n");
 255     GNUNET_break (0);
 256     ok = 2;
 257     GNUNET_SCHEDULER_cancel (die_task);
 258     GNUNET_SCHEDULER_add_now (&end_task, NULL);
 259     return;
 260   }
 261
 262   GNUNET_SCHEDULER_cancel (die_task);
 263   GNUNET_SCHEDULER_add_now (&end_task, NULL);
 264 }
 265
 266 static void
 267 runone ()
 268 {
 269   const struct GNUNET_DISK_FileHandle *stdout_read_handle;
 270
 271   pipe_stdout = GNUNET_DISK_pipe (GNUNET_YES, GNUNET_NO, GNUNET_YES);
 272
 273   if (pipe_stdout == NULL)
 274   {
 275     GNUNET_break (0);
 276     ok = 2;
 277     return;
 278   }
 279
 280   putenv ("GNUNET_LOG=");
 281   putenv ("GNUNET_FORCE_LOG=");
 282   putenv ("GNUNET_FORCE_LOGFILE=");
 283   switch (phase)
 284   {
 285   case 0:
 286     putenv ("GNUNET_LOG=;;;;ERROR");
 287     break;
 288   case 1:
 289     putenv ("GNUNET_LOG=;;;;WARNING");
 290     break;
 291   case 2:
 292     putenv ("GNUNET_LOG=;;;;INFO");
 293     break;
 294   case 3:
 295     putenv ("GNUNET_LOG=;;;;DEBUG");
 296     break;
 297   case 4:
 298     putenv ("GNUNET_FORCE_LOG=;;;;ERROR");
 299     break;
 300   case 5:
 301     putenv ("GNUNET_FORCE_LOG=;;;;WARNING");
 302     break;
 303   case 6:
 304     putenv ("GNUNET_FORCE_LOG=;;;;INFO");
 305     break;
 306   case 7:
 307     putenv ("GNUNET_FORCE_LOG=;;;;DEBUG");
 308     break;
 309   case 8:
 310     putenv ("GNUNET_LOG=blah;;;;ERROR");
 311     break;
 312   case 9:
 313     putenv ("GNUNET_FORCE_LOG=blah;;;;ERROR");
 314     break;
 315   }
 316
 317   proc = GNUNET_OS_start_process (NULL, pipe_stdout,
 318 #if MINGW
 319                                   "test_common_logging_dummy",
 320 #else
 321                                   "./test_common_logging_dummy",
 322 #endif
 323                                   "test_common_logging_dummy", NULL);
 324   putenv ("GNUNET_FORCE_LOG=");
 325   putenv ("GNUNET_LOG=");
 326
 327   /* Close the write end of the read pipe */
 328   GNUNET_DISK_pipe_close_end (pipe_stdout, GNUNET_DISK_PIPE_END_WRITE);
 329
 330   stdout_read_handle =
 331       GNUNET_DISK_pipe_handle (pipe_stdout, GNUNET_DISK_PIPE_END_READ);
 332
 333   die_task =
 334       GNUNET_SCHEDULER_add_delayed (GNUNET_TIME_relative_multiply
 335                                     (GNUNET_TIME_UNIT_SECONDS, 10), &end_task,
 336                                     NULL);
 337
 338   bytes = 0;
 339   buf_ptr = buf;
 340   memset (&buf, 0, sizeof (buf));
 341
 342   GNUNET_SCHEDULER_add_read_file (GNUNET_TIME_UNIT_FOREVER_REL,
 343                                   stdout_read_handle, &read_call,
 344                                   (void *) stdout_read_handle);
 345 }
 346
 347 static void
 348 task (void *cls, const struct GNUNET_SCHEDULER_TaskContext *tc)
 349 {
 350   phase = 0;
 351   runone ();
 352 }
 353
 354 /**
 355  * Main method, starts scheduler with task1,
 356  * checks that "ok" is correct at the end.
 357  */
 358 static int
 359 check ()
 360 {
 361   ok = 1;
 362   GNUNET_SCHEDULER_run (&task, &ok);
 363   return ok;
 364 }
 365
 366
 367 int
 368 main (int argc, char *argv[])
 369 {
 370   int ret;
 371
 372   GNUNET_log_setup ("test-common-logging-runtime-loglevels",
 373 #if VERBOSE
 374                     "DEBUG",
 375 #else
 376                     "WARNING",
 377 #endif
 378                     NULL);
 379   ret = check ();
 380
 381   return ret;
 382 }
 383
 384 /* end of test_common_logging_runtime_loglevels.c */