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