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