X-Git-Url: https://review.openocd.org/gitweb?p=openocd.git;a=blobdiff_plain;f=src%2Fhelper%2Flog.c;h=e5f6d3d6c58eae398462aff658d03c0fcd51407c;hp=694e8a8b2126aa98b181f8bcd8e3c5d1051ebf47;hb=68c598e88d5e09728ea845a81ab279c615bbaf0f;hpb=d74d72c73a692fbdf222c4cb595a5d015f4611c9 diff --git a/src/helper/log.c b/src/helper/log.c index 694e8a8b21..e5f6d3d6c5 100644 --- a/src/helper/log.c +++ b/src/helper/log.c @@ -2,6 +2,12 @@ * Copyright (C) 2005 by Dominic Rath * * Dominic.Rath@gmx.de * * * + * Copyright (C) 2007,2008 Øyvind Harboe * + * oyvind.harboe@zylin.com * + * * + * Copyright (C) 2008 by Spencer Oliver * + * spen@spen-soft.co.uk * + * * * This program is free software; you can redistribute it and/or modify * * it under the terms of the GNU General Public License as published by * * the Free Software Foundation; either version 2 of the License, or * @@ -23,19 +29,28 @@ #include "log.h" #include "configuration.h" +#include "time_support.h" +#include "command.h" #include #include #include #include -#include + +#define PRINT_MEM() 0 +#if PRINT_MEM() +#include +#endif int debug_level = -1; static FILE* log_output; static log_callback_t *log_callbacks = NULL; -static time_t start; +static long long last_time; +static long long current_time; + +static long long start; static char *log_strings[5] = { @@ -49,18 +64,19 @@ static char *log_strings[5] = static int count = 0; /* The log_puts() serves to somewhat different goals: - * + * * - logging * - feeding low-level info to the user in GDB or Telnet - * + * * The latter dictates that strings without newline are not logged, lest there - * will be *MANY log lines when sending one char at the time(e.g. + * will be *MANY log lines when sending one char at the time(e.g. * target_request.c). - * + * */ static void log_puts(enum log_levels level, const char *file, int line, const char *function, const char *string) { - if (level == LOG_OUTPUT) + char *f; + if (level == LOG_LVL_OUTPUT) { /* do not prepend any headers, just print out what we were given and return */ fputs(string, log_output); @@ -68,33 +84,49 @@ static void log_puts(enum log_levels level, const char *file, int line, const ch return; } - char *f = strrchr(file, '/'); + f = strrchr(file, '/'); if (f != NULL) file = f + 1; if (strchr(string, '\n')!=NULL) { - if (debug_level >= LOG_DEBUG) + if (debug_level >= LOG_LVL_DEBUG) { /* print with count and time information */ - int t=(int)(time(NULL)-start); - fprintf(log_output, "%s %d %d %s:%d %s(): %s", log_strings[level+1], count, t, file, line, function, string); + int t=(int)(timeval_ms()-start); +#if PRINT_MEM() + struct mallinfo info; + info = mallinfo(); +#endif + fprintf(log_output, "%s %d %d %s:%d %s()" +#if PRINT_MEM() + " %d" +#endif + ": %s", log_strings[level+1], count, t, file, line, function, +#if PRINT_MEM() + info.fordblks, +#endif + string); } else { - /* do not print count and time */ - fprintf(log_output, "%s %s:%d %s(): %s", log_strings[level+1], file, line, function, string); + if (strcmp(string, "\n")!=0) + { + /* print human readable output - but skip empty lines */ + fprintf(log_output, "%s%s", + (level > LOG_LVL_USER)?log_strings[level+1]:"", string); + } } } else { - /* only entire lines are logged. Otherwise it's + /* only entire lines are logged. Otherwise it's * single chars intended for the log callbacks. */ } fflush(log_output); - - /* Never forward LOG_DEBUG, too verbose and they can be found in the log if need be */ - if (level <= LOG_INFO) + + /* Never forward LOG_LVL_DEBUG, too verbose and they can be found in the log if need be */ + if (level <= LOG_LVL_INFO) { log_callback_t *cb, *next; cb = log_callbacks; @@ -111,43 +143,43 @@ static void log_puts(enum log_levels level, const char *file, int line, const ch void log_printf(enum log_levels level, const char *file, int line, const char *function, const char *format, ...) { char *string; + va_list ap; count++; if (level > debug_level) return; - va_list ap; va_start(ap, format); - string = alloc_printf(format, ap); + string = alloc_vprintf(format, ap); if (string != NULL) { log_puts(level, file, line, function, string); free(string); } - + va_end(ap); } void log_printf_lf(enum log_levels level, const char *file, int line, const char *function, const char *format, ...) { char *string; + va_list ap; count++; if (level > debug_level) return; - - va_list ap; + va_start(ap, format); - - string = alloc_printf(format, ap); + + string = alloc_vprintf(format, ap); if (string != NULL) { - strcat(string, "\n"); /* alloc_printf guaranteed the buffer to be at least one char longer */ + strcat(string, "\n"); /* alloc_vprintf guaranteed the buffer to be at least one char longer */ log_puts(level, file, line, function, string); free(string); } - + va_end(ap); } @@ -179,7 +211,7 @@ int handle_log_output_command(struct command_context_s *cmd_ctx, char *cmd, char if (argc == 1) { FILE* file = fopen(args[0], "w"); - + if (file) { log_output = file; @@ -191,7 +223,7 @@ int handle_log_output_command(struct command_context_s *cmd_ctx, char *cmd, char int log_register_commands(struct command_context_s *cmd_ctx) { - start = time(NULL); + start = timeval_ms(); register_command(cmd_ctx, NULL, "log_output", handle_log_output_command, COMMAND_ANY, "redirect logging to (default: stderr)"); register_command(cmd_ctx, NULL, "debug_level", handle_debug_level_command, @@ -204,16 +236,18 @@ int log_init(struct command_context_s *cmd_ctx) { /* set defaults for daemon configuration, if not set by cmdline or cfgfile */ if (debug_level == -1) - debug_level = LOG_INFO; - + debug_level = LOG_LVL_INFO; + if (log_output == NULL) { log_output = stderr; } - + + start=last_time=timeval_ms(); + return ERROR_OK; } - + int set_log_output(struct command_context_s *cmd_ctx, FILE *output) { log_output = output; @@ -264,17 +298,19 @@ int log_remove_callback(log_callback_fn fn, void *priv) } /* return allocated string w/printf() result */ -char *alloc_printf(const char *fmt, va_list ap) +char *alloc_vprintf(const char *fmt, va_list ap) { /* no buffer at the beginning, force realloc to do the job */ char *string = NULL; - + /* start with buffer size suitable for typical messages */ int size = 128; for (;;) { char *t = string; + va_list ap_copy; + int ret; string = realloc(string, size); if (string == NULL) { @@ -283,14 +319,9 @@ char *alloc_printf(const char *fmt, va_list ap) return NULL; } - va_list ap_copy; va_copy(ap_copy, ap); - int ret; ret = vsnprintf(string, size, fmt, ap_copy); - - va_end(ap_copy); - /* NB! The result of the vsnprintf() might be an *EMPTY* string! */ if ((ret >= 0) && ((ret + 1) < size)) break; @@ -298,7 +329,86 @@ char *alloc_printf(const char *fmt, va_list ap) /* there was just enough or not enough space, allocate more in the next round */ size *= 2; /* double the buffer size */ } - + /* the returned buffer is by principle guaranteed to be at least one character longer */ return string; } + +char *alloc_printf(const char *format, ...) +{ + char *string; + va_list ap; + va_start(ap, format); + string = alloc_vprintf(format, ap); + va_end(ap); + return string; +} + +/* Code must return to the server loop before 1000ms has returned or invoke + * this function. + * + * The GDB connection will time out if it spends >2000ms and you'll get nasty + * error messages from GDB: + * + * Ignoring packet error, continuing... + * Reply contains invalid hex digit 116 + * + * While it is possible use "set remotetimeout" to more than the default 2000ms + * in GDB, OpenOCD guarantees that it sends keep-alive packages on the + * GDB protocol and it is a bug in OpenOCD not to either return to the server + * loop or invoke keep_alive() every 1000ms. + * + * This function will send a keep alive packet if >500ms has passed since last time + * it was invoked. + * + * Note that this function can be invoked often, so it needs to be relatively + * fast when invoked more often than every 500ms. + * + */ +void keep_alive() +{ + current_time=timeval_ms(); + if (current_time-last_time>1000) + { + LOG_WARNING("BUG: keep_alive() was not invoked in the 1000ms timelimit. GDB alive packet not sent! (%lld)", current_time-last_time); + } + if (current_time-last_time>500) + { + /* this will keep the GDB connection alive */ + LOG_USER_N("%s", ""); + + /* DANGER!!!! do not add code to invoke e.g. target event processing, + * jim timer processing, etc. it can cause infinite recursion + + * jim event callbacks need to happen at a well defined time, + * not anywhere keep_alive() is invoked. + * + * These functions should be invoked at a well defined spot in server.c + */ + + last_time=current_time; + } +} + +/* reset keep alive timer without sending message */ +void kept_alive() +{ + current_time=timeval_ms(); + last_time=current_time; +} + +/* if we sleep for extended periods of time, we must invoke keep_alive() intermittantly */ +void alive_sleep(int ms) +{ + int i; + for (i=0; i500) + { + sleep_a_bit=500; + } + keep_alive(); + usleep(sleep_a_bit*1000); + keep_alive(); + } +}