2 This file is part of GNUnet.
3 (C) 2011 Christian Grothoff (and other contributing authors)
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.
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.
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.
22 * @file util/test_common_logging_runtime_loglevels.c
23 * @brief testcase for the logging module (runtime log level adjustment)
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"
33 #define VERBOSE GNUNET_NO
36 * How much time the child is allowed to waste on skipped log calls, at most.
37 * Raspberry Pi takes 33 microseconds tops, this is 3x that value.
39 #define MAX_SKIP_DELAY GNUNET_TIME_relative_multiply (GNUNET_TIME_UNIT_MICROSECONDS, 100).rel_value_us
42 * How much time non-skipped log call should take, at least.
43 * Keep in sync with the value in the dummy!
45 #define OUTPUT_DELAY GNUNET_TIME_relative_multiply (GNUNET_TIME_UNIT_MICROSECONDS, 200).rel_value_us
51 static struct GNUNET_OS_Process *proc;
53 /* Pipe to read from started processes stdout (on read end) */
54 static struct GNUNET_DISK_PipeHandle *pipe_stdout;
56 static GNUNET_SCHEDULER_TaskIdentifier die_task;
58 static GNUNET_SCHEDULER_TaskIdentifier read_task;
65 end_task (void *cls, const struct GNUNET_SCHEDULER_TaskContext *tc)
67 GNUNET_log (GNUNET_ERROR_TYPE_DEBUG, "Ending phase %d, ok is %d\n", phase,
71 if (0 != GNUNET_OS_process_kill (proc, SIGTERM))
73 GNUNET_log_strerror (GNUNET_ERROR_TYPE_WARNING, "kill");
75 GNUNET_OS_process_wait (proc);
76 GNUNET_OS_process_destroy (proc);
79 if (GNUNET_SCHEDULER_NO_TASK != read_task)
81 GNUNET_SCHEDULER_cancel (read_task);
82 read_task = GNUNET_SCHEDULER_NO_TASK;
84 GNUNET_DISK_pipe_close (pipe_stdout);
96 GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "failing\n");
101 read_output_line (int phase_from1, int phase_to1, int phase_from2,
102 int phase_to2, char c, const char *expect_level,
103 long delay_morethan, long delay_lessthan, int phase,
105 int *len, long *delay, char level[8])
112 int delay_is_a_dummy;
113 int delay_outside_of_range;
118 if (!(phase >= phase_from1 && phase <= phase_to1) &&
119 !(phase >= phase_from2 && phase <= phase_to2))
122 GNUNET_log (GNUNET_ERROR_TYPE_DEBUG,
123 "Trying to match '%c%s \\d\\r\\n' on %s\n", c, expect_level, p);
125 for (i = 0; i < *len && !stop; i++)
129 case 0: /* read first char */
132 GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "Expected '%c', but got '%c'\n", c,
139 case 1: /* read at most 7 char-long error level string, finished by ' ' */
155 case 2: /* read the delay, finished by '\n' */
158 if (r[i] == '\r' && r[i + 1] == '\n')
162 *delay = strtol (t, NULL, 10);
169 *delay = strtol (t, NULL, 10);
176 level_matches = (strcmp (expect_level, level) == 0);
177 delay_is_sane = (*delay >= 0) && (*delay <= 1000000);
178 delay_is_a_dummy = (c == 'L');
179 /* Delay must be either less than 'lessthan' (log call is skipped)
180 * or more than 'morethan' (log call is not skipped)
182 delay_outside_of_range = ((*delay < delay_lessthan) || (*delay > delay_morethan));
183 if (delay_is_a_dummy)
184 delay_outside_of_range = 1;
187 GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "Wrong log format?\n");
189 GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "Wrong log level\n");
191 GNUNET_log (GNUNET_ERROR_TYPE_ERROR, "Delay %ld is insane\n", *delay);
192 if (!delay_outside_of_range)
193 GNUNET_log (GNUNET_ERROR_TYPE_ERROR,
194 "Delay %ld is not outside of range (%ld ; %ld)\n",
195 *delay, delay_lessthan, delay_morethan, c);
196 if (!stop || !level_matches || !delay_is_sane || !delay_outside_of_range)
203 * Up to 8 non-skipped GNUNET_log() calls
204 * + extra line with delay for each one
206 #define LOG_MAX_NUM_LINES (8 * 2)
208 * Actual message is 17 chars at most
210 #define LOG_MAX_LINE_LENGTH (17)
212 #define LOG_BUFFER_SIZE LOG_MAX_NUM_LINES * LOG_MAX_LINE_LENGTH
214 static char buf[LOG_BUFFER_SIZE];
216 static char *buf_ptr;
222 read_call (void *cls, const struct GNUNET_SCHEDULER_TaskContext *tc)
224 const struct GNUNET_DISK_FileHandle *stdout_read_handle = cls;
230 read_task = GNUNET_SCHEDULER_NO_TASK;
231 rd = GNUNET_DISK_file_read (stdout_read_handle, buf_ptr,
232 sizeof (buf) - bytes);
238 FPRINTF (stderr, "got %d bytes, reading more\n", rd);
240 read_task = GNUNET_SCHEDULER_add_read_file (GNUNET_TIME_UNIT_FOREVER_REL,
241 stdout_read_handle, &read_call,
242 (void*) stdout_read_handle);
247 FPRINTF (stderr, "bytes is %d:%s\n", bytes, buf);
250 /* +------CHILD OUTPUT--
261 * | 7D * * * * * * * *
267 if (bytes == LOG_BUFFER_SIZE ||
269 read_output_line (0, 3, 4, 9, 'L', "ERROR", -1,
271 &bytes, &delay, level)) ||
273 read_output_line (0, 3, 4, 9, '1', "ERROR", OUTPUT_DELAY,
274 MAX_SKIP_DELAY, phase, p,
275 &bytes, &delays[0], level)) ||
277 read_output_line (1, 3, 5, 9, 'L', "WARNING", -1,
279 &bytes, &delay, level)) ||
281 read_output_line (0, 3, 4, 9, '1', "WARNING", OUTPUT_DELAY,
282 MAX_SKIP_DELAY, phase, p,
283 &bytes, &delays[1], level)) ||
285 read_output_line (2, 3, 6, 7, 'L', "INFO", -1,
287 &bytes, &delay, level)) ||
289 read_output_line (0, 3, 4, 9, '1', "INFO", OUTPUT_DELAY,
290 MAX_SKIP_DELAY, phase, p,
291 &bytes, &delays[2], level)) ||
293 read_output_line (3, 3, 7, 7, 'L', "DEBUG", -1,
295 &bytes, &delay, level)) ||
297 read_output_line (0, 3, 4, 9, '1', "DEBUG", OUTPUT_DELAY,
298 MAX_SKIP_DELAY, phase, p,
299 &bytes, &delays[3], level)) ||
301 read_output_line (0, 3, 4, 9, 'L', "ERROR", -1,
303 &bytes, &delay, level)) ||
305 read_output_line (0, 3, 4, 9, '2', "ERROR", OUTPUT_DELAY,
306 MAX_SKIP_DELAY, phase, p,
307 &bytes, &delays[4], level)) ||
309 read_output_line (0, 3, 5, 9, 'L', "WARNING", -1,
311 &bytes, &delay, level)) ||
313 read_output_line (0, 3, 4, 9, '2', "WARNING", OUTPUT_DELAY,
314 MAX_SKIP_DELAY, phase, p,
315 &bytes, &delays[5], level)) ||
317 read_output_line (-1, -1, 6, 7, 'L', "INFO", -1,
319 &bytes, &delay, level)) ||
321 read_output_line (0, 3, 4, 9, '2', "INFO", OUTPUT_DELAY,
322 MAX_SKIP_DELAY, phase, p,
323 &bytes, &delays[6], level)) ||
325 read_output_line (-1, -1, 7, 7, 'L', "DEBUG", -1,
327 &bytes, &delay, level)) ||
329 read_output_line (0, 3, 4, 9, '2', "DEBUG", OUTPUT_DELAY,
330 MAX_SKIP_DELAY, phase, p,
331 &bytes, &delays[7], level)))
333 if (bytes == LOG_BUFFER_SIZE)
334 FPRINTF (stderr, "%s", "Ran out of buffer space!\n");
337 GNUNET_SCHEDULER_cancel (die_task);
338 GNUNET_SCHEDULER_add_now (&end_task, NULL);
342 GNUNET_SCHEDULER_cancel (die_task);
343 GNUNET_SCHEDULER_add_now (&end_task, NULL);
350 const struct GNUNET_DISK_FileHandle *stdout_read_handle;
352 pipe_stdout = GNUNET_DISK_pipe (GNUNET_YES, GNUNET_YES, GNUNET_NO, GNUNET_YES);
354 if (pipe_stdout == NULL)
361 putenv ("GNUNET_LOG=");
362 putenv ("GNUNET_FORCE_LOG=");
363 putenv ("GNUNET_FORCE_LOGFILE=");
367 putenv ("GNUNET_LOG=;;;;ERROR");
370 putenv ("GNUNET_LOG=;;;;WARNING");
373 putenv ("GNUNET_LOG=;;;;INFO");
376 putenv ("GNUNET_LOG=;;;;DEBUG");
379 putenv ("GNUNET_FORCE_LOG=;;;;ERROR");
382 putenv ("GNUNET_FORCE_LOG=;;;;WARNING");
385 putenv ("GNUNET_FORCE_LOG=;;;;INFO");
388 putenv ("GNUNET_FORCE_LOG=;;;;DEBUG");
391 putenv ("GNUNET_LOG=blah;;;;ERROR");
394 putenv ("GNUNET_FORCE_LOG=blah;;;;ERROR");
398 proc = GNUNET_OS_start_process (GNUNET_NO, GNUNET_OS_INHERIT_STD_OUT_AND_ERR, NULL, pipe_stdout,
400 "test_common_logging_dummy",
402 "./test_common_logging_dummy",
404 "test_common_logging_dummy", NULL);
405 GNUNET_assert (NULL != proc);
406 putenv ("GNUNET_FORCE_LOG=");
407 putenv ("GNUNET_LOG=");
409 /* Close the write end of the read pipe */
410 GNUNET_DISK_pipe_close_end (pipe_stdout, GNUNET_DISK_PIPE_END_WRITE);
413 GNUNET_DISK_pipe_handle (pipe_stdout, GNUNET_DISK_PIPE_END_READ);
416 GNUNET_SCHEDULER_add_delayed (GNUNET_TIME_relative_multiply
417 (GNUNET_TIME_UNIT_SECONDS, 10), &end_task,
422 memset (&buf, 0, sizeof (buf));
424 read_task = GNUNET_SCHEDULER_add_read_file (GNUNET_TIME_UNIT_FOREVER_REL,
425 stdout_read_handle, &read_call,
426 (void*) stdout_read_handle);
431 task (void *cls, const struct GNUNET_SCHEDULER_TaskContext *tc)
439 main (int argc, char *argv[])
441 GNUNET_log_setup ("test-common-logging-runtime-loglevels",
445 GNUNET_SCHEDULER_run (&task, &ok);
449 /* end of test_common_logging_runtime_loglevels.c */