X-Git-Url: https://review.openocd.org/gitweb?p=openocd.git;a=blobdiff_plain;f=src%2Fhelper%2Flog.c;h=68b29a203b5cda1f27f2e4d9287551db332731b0;hp=ca9f0a7b45d1dadc4cdb2acb9844092c6d348c28;hb=84df52f9ea78e2d71bde648a16b69d80404c6421;hpb=2c3f0ebae9499a70314ba4520099d0006eb8e7fe diff --git a/src/helper/log.c b/src/helper/log.c index ca9f0a7b45..68b29a203b 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 * @@ -22,17 +28,18 @@ #endif #include "log.h" -#include "configuration.h" #include "time_support.h" +// @todo the inclusion of server.h here is a layering violation +#include "server.h" -#include -#include -#include #include -#define PRINT_MEM() 0 -#if PRINT_MEM() +#ifdef _DEBUG_FREE_SPACE_ +#ifdef HAVE_MALLOC_H #include +#else +#error "malloc.h is required to use --enable-malloc-logging" +#endif #endif int debug_level = -1; @@ -47,24 +54,25 @@ static long long start; static char *log_strings[5] = { - "User: ", - "Error: ", - "Warning:", - "Info: ", - "Debug: " + "User : ", + "Error: ", + "Warn : ", /* want a space after each colon, all same width, colons aligned */ + "Info : ", + "Debug: " }; + 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) { @@ -81,39 +89,45 @@ static void log_puts(enum log_levels level, const char *file, int line, const ch if (f != NULL) file = f + 1; - if (strchr(string, '\n')!=NULL) + if (strchr(string, '\n') != NULL) { if (debug_level >= LOG_LVL_DEBUG) { /* print with count and time information */ - int t=(int)(timeval_ms()-start); -#if PRINT_MEM() + int t = (int)(timeval_ms()-start); +#ifdef _DEBUG_FREE_SPACE_ struct mallinfo info; info = mallinfo(); #endif - fprintf(log_output, "%s %d %d %s:%d %s()" -#if PRINT_MEM() + fprintf(log_output, "%s%d %d %s:%d %s()" +#ifdef _DEBUG_FREE_SPACE_ " %d" #endif - ": %s", log_strings[level+1], count, t, file, line, function, -#if PRINT_MEM() + ": %s", log_strings[level+1], count, t, file, line, function, +#ifdef _DEBUG_FREE_SPACE_ info.fordblks, #endif string); } - else + else if (server_use_pipes == 0) { - /* do not print count and time */ - fprintf(log_output, "%s %s:%d %s(): %s", log_strings[level+1], file, line, function, string); + /* if we are using gdb through pipes then we do not want any output + * to the pipe otherwise we get repeated strings */ + 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_LVL_DEBUG, too verbose and they can be found in the log if need be */ if (level <= LOG_LVL_INFO) { @@ -122,9 +136,9 @@ static void log_puts(enum log_levels level, const char *file, int line, const ch /* DANGER!!!! the log callback can remove itself!!!! */ while (cb) { - next=cb->next; + next = cb->next; cb->fn(cb->priv, file, line, function, string); - cb=next; + cb = next; } } } @@ -146,7 +160,7 @@ void log_printf(enum log_levels level, const char *file, int line, const char *f log_puts(level, file, line, function, string); free(string); } - + va_end(ap); } @@ -158,9 +172,9 @@ void log_printf_lf(enum log_levels level, const char *file, int line, const char count++; if (level > debug_level) return; - + va_start(ap, format); - + string = alloc_vprintf(format, ap); if (string != NULL) { @@ -168,7 +182,7 @@ void log_printf_lf(enum log_levels level, const char *file, int line, const char log_puts(level, file, line, function, string); free(string); } - + va_end(ap); } @@ -180,17 +194,30 @@ void log_printf_lf(enum log_levels level, const char *file, int line, const char */ int handle_debug_level_command(struct command_context_s *cmd_ctx, char *cmd, char **args, int argc) { - if (argc == 0) - command_print(cmd_ctx, "debug_level: %i", debug_level); - - if (argc > 0) - debug_level = strtoul(args[0], NULL, 0); + if (argc == 1) + { + unsigned new_level; + int retval = parse_uint(args[0], &new_level); + if (ERROR_OK != retval) + return retval; + debug_level = MIN(new_level, LOG_LVL_DEBUG); + } + else if (argc > 1) + return ERROR_COMMAND_SYNTAX_ERROR; - if (debug_level < 0) - debug_level = 0; + if (debug_level >= LOG_LVL_DEBUG && server_use_pipes == 1) + { + /* if we are enabling debug info then we need to write to a log file + * otherwise the pipe will get full and cause issues with gdb */ + FILE* file = fopen("openocd.log", "w"); + if (file) + { + log_output = file; + LOG_WARNING("enabling log output as we are using pipes"); + } + } - if (debug_level > 3) - debug_level = 3; + command_print(cmd_ctx, "debug_level: %i", debug_level); return ERROR_OK; } @@ -200,7 +227,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; @@ -226,17 +253,17 @@ 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_LVL_INFO; - + if (log_output == NULL) { log_output = stderr; } - - start=last_time=timeval_ms(); - + + start = last_time = timeval_ms(); + return ERROR_OK; } - + int set_log_output(struct command_context_s *cmd_ctx, FILE *output) { log_output = output; @@ -291,7 +318,7 @@ 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; @@ -318,7 +345,7 @@ char *alloc_vprintf(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; } @@ -335,10 +362,10 @@ char *alloc_printf(const char *format, ...) /* 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 * @@ -346,29 +373,80 @@ char *alloc_printf(const char *format, ...) * 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(); + current_time = timeval_ms(); if (current_time-last_time>1000) { - LOG_WARNING("keep_alive() was not invoked in the 1000ms timelimit. GDB alive packet not sent! (%lld)", current_time-last_time); - last_time=current_time; - } else if (current_time-last_time>500) + extern int gdb_actual_connections; + + if (gdb_actual_connections) + LOG_WARNING("keep_alive() was not invoked in the " + "1000ms timelimit. GDB alive packet not " + "sent! (%lld). Workaround: increase " + "\"set remotetimeout\" in GDB", + current_time-last_time); + else + LOG_DEBUG("keep_alive() was not invoked in the " + "1000ms timelimit (%lld). This may cause " + "trouble with GDB connections.", + current_time-last_time); + } + if (current_time-last_time>500) { /* this will keep the GDB connection alive */ LOG_USER_N("%s", ""); - last_time=current_time; + + /* 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; + 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; + int napTime = 10; + for (i = 0; inapTime) + { + sleep_a_bit = napTime; + } + usleep(sleep_a_bit*1000); + keep_alive(); + } +} + +void busy_sleep(int ms) +{ + long long then; + then = timeval_ms(); + while ((timeval_ms()-then)