src/helper/log.c

   1 /***************************************************************************
   2  *   Copyright (C) 2005 by Dominic Rath                                    *
   3  *   Dominic.Rath@gmx.de                                                   *
   4  *                                                                         *
   5  *   This program is free software; you can redistribute it and/or modify  *
   6  *   it under the terms of the GNU General Public License as published by  *
   7  *   the Free Software Foundation; either version 2 of the License, or     *
   8  *   (at your option) any later version.                                   *
   9  *                                                                         *
  10  *   This program is distributed in the hope that it will be useful,       *
  11  *   but WITHOUT ANY WARRANTY; without even the implied warranty of        *
  12  *   MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the         *
  13  *   GNU General Public License for more details.                          *
  14  *                                                                         *
  15  *   You should have received a copy of the GNU General Public License     *
  16  *   along with this program; if not, write to the                         *
  17  *   Free Software Foundation, Inc.,                                       *
  18  *   59 Temple Place - Suite 330, Boston, MA  02111-1307, USA.             *
  19  ***************************************************************************/
  20 #ifdef HAVE_CONFIG_H
  21 #include "config.h"
  22 #endif
  23
  24 #include "log.h"
  25 #include "configuration.h"
  26 #include "time_support.h"
  27
  28 #include <stdio.h>
  29 #include <stdlib.h>
  30 #include <string.h>
  31 #include <stdarg.h>
  32
  33 #define PRINT_MEM() 0
  34 #if PRINT_MEM()
  35 #include <malloc.h>
  36 #endif
  37
  38 int debug_level = -1;
  39
  40 static FILE* log_output;
  41 static log_callback_t *log_callbacks = NULL;
  42
  43 static long long last_time;
  44 static long long current_time;
  45
  46 static long long start;
  47
  48 static char *log_strings[5] =
  49 {
  50         "User:   ",
  51         "Error:  ",
  52         "Warning:",
  53         "Info:   ",
  54         "Debug:  "
  55 };
  56
  57 static int count = 0;
  58
  59 /* The log_puts() serves to somewhat different goals:
  60  *
  61  * - logging
  62  * - feeding low-level info to the user in GDB or Telnet
  63  *
  64  * The latter dictates that strings without newline are not logged, lest there
  65  * will be *MANY log lines when sending one char at the time(e.g.
  66  * target_request.c).
  67  *
  68  */
  69 static void log_puts(enum log_levels level, const char *file, int line, const char *function, const char *string)
  70 {
  71         char *f;
  72         if (level == LOG_LVL_OUTPUT)
  73         {
  74                 /* do not prepend any headers, just print out what we were given and return */
  75                 fputs(string, log_output);
  76                 fflush(log_output);
  77                 return;
  78         }
  79
  80         f = strrchr(file, '/');
  81         if (f != NULL)
  82                 file = f + 1;
  83
  84         if (strchr(string, '\n')!=NULL)
  85         {
  86                 if (debug_level >= LOG_LVL_DEBUG)
  87                 {
  88                         /* print with count and time information */
  89                         int t=(int)(timeval_ms()-start);
  90 #if PRINT_MEM()
  91                         struct mallinfo info;
  92                         info = mallinfo();
  93 #endif
  94                         fprintf(log_output, "%s %d %d %s:%d %s()"
  95 #if PRINT_MEM()
  96                                         " %d"
  97 #endif
  98                                         ": %s", log_strings[level+1], count, t, file, line, function,
  99 #if PRINT_MEM()
 100                                         info.fordblks,
 101 #endif
 102                                         string);
 103                 }
 104                 else
 105                 {
 106                         /* do not print count and time */
 107                         fprintf(log_output, "%s %s:%d %s(): %s", log_strings[level+1], file, line, function, string);
 108                 }
 109         } else
 110         {
 111                 /* only entire lines are logged. Otherwise it's
 112                  * single chars intended for the log callbacks. */
 113         }
 114
 115         fflush(log_output);
 116
 117         /* Never forward LOG_LVL_DEBUG, too verbose and they can be found in the log if need be */
 118         if (level <= LOG_LVL_INFO)
 119         {
 120                 log_callback_t *cb, *next;
 121                 cb = log_callbacks;
 122                 /* DANGER!!!! the log callback can remove itself!!!! */
 123                 while (cb)
 124                 {
 125                         next=cb->next;
 126                         cb->fn(cb->priv, file, line, function, string);
 127                         cb=next;
 128                 }
 129         }
 130 }
 131
 132 void log_printf(enum log_levels level, const char *file, int line, const char *function, const char *format, ...)
 133 {
 134         char *string;
 135         va_list ap;
 136
 137         count++;
 138         if (level > debug_level)
 139                 return;
 140
 141         va_start(ap, format);
 142
 143         string = alloc_vprintf(format, ap);
 144         if (string != NULL)
 145         {
 146                 log_puts(level, file, line, function, string);
 147                 free(string);
 148         }
 149
 150         va_end(ap);
 151 }
 152
 153 void log_printf_lf(enum log_levels level, const char *file, int line, const char *function, const char *format, ...)
 154 {
 155         char *string;
 156         va_list ap;
 157
 158         count++;
 159         if (level > debug_level)
 160                 return;
 161
 162         va_start(ap, format);
 163
 164         string = alloc_vprintf(format, ap);
 165         if (string != NULL)
 166         {
 167                 strcat(string, "\n"); /* alloc_vprintf guaranteed the buffer to be at least one char longer */
 168                 log_puts(level, file, line, function, string);
 169                 free(string);
 170         }
 171
 172         va_end(ap);
 173 }
 174
 175 /* change the current debug level on the fly
 176  * 0: only ERRORS
 177  * 1: + WARNINGS
 178  * 2: + INFORMATIONAL MSGS
 179  * 3: + DEBUG MSGS
 180  */
 181 int handle_debug_level_command(struct command_context_s *cmd_ctx, char *cmd, char **args, int argc)
 182 {
 183         if (argc == 0)
 184                 command_print(cmd_ctx, "debug_level: %i", debug_level);
 185
 186         if (argc > 0)
 187                 debug_level = strtoul(args[0], NULL, 0);
 188
 189         if (debug_level < 0)
 190                 debug_level = 0;
 191
 192         if (debug_level > 3)
 193                 debug_level = 3;
 194
 195         return ERROR_OK;
 196 }
 197
 198 int handle_log_output_command(struct command_context_s *cmd_ctx, char *cmd, char **args, int argc)
 199 {
 200         if (argc == 1)
 201         {
 202                 FILE* file = fopen(args[0], "w");
 203
 204                 if (file)
 205                 {
 206                         log_output = file;
 207                 }
 208         }
 209
 210         return ERROR_OK;
 211 }
 212
 213 int log_register_commands(struct command_context_s *cmd_ctx)
 214 {
 215         start = timeval_ms();
 216         register_command(cmd_ctx, NULL, "log_output", handle_log_output_command,
 217                 COMMAND_ANY, "redirect logging to <file> (default: stderr)");
 218         register_command(cmd_ctx, NULL, "debug_level", handle_debug_level_command,
 219                 COMMAND_ANY, "adjust debug level <0-3>");
 220
 221         return ERROR_OK;
 222 }
 223
 224 int log_init(struct command_context_s *cmd_ctx)
 225 {
 226         /* set defaults for daemon configuration, if not set by cmdline or cfgfile */
 227         if (debug_level == -1)
 228                 debug_level = LOG_LVL_INFO;
 229
 230         if (log_output == NULL)
 231         {
 232                 log_output = stderr;
 233         }
 234
 235         start=last_time=timeval_ms();
 236
 237         return ERROR_OK;
 238 }
 239
 240 int set_log_output(struct command_context_s *cmd_ctx, FILE *output)
 241 {
 242         log_output = output;
 243         return ERROR_OK;
 244 }
 245
 246 /* add/remove log callback handler */
 247 int log_add_callback(log_callback_fn fn, void *priv)
 248 {
 249         log_callback_t *cb;
 250
 251         /* prevent the same callback to be registered more than once, just for sure */
 252         for (cb = log_callbacks; cb; cb = cb->next)
 253         {
 254                 if (cb->fn == fn && cb->priv == priv)
 255                         return ERROR_INVALID_ARGUMENTS;
 256         }
 257
 258         /* alloc memory, it is safe just to return in case of an error, no need for the caller to check this */
 259         if ((cb = malloc(sizeof(log_callback_t))) == NULL)
 260                 return ERROR_BUF_TOO_SMALL;
 261
 262         /* add item to the beginning of the linked list */
 263         cb->fn = fn;
 264         cb->priv = priv;
 265         cb->next = log_callbacks;
 266         log_callbacks = cb;
 267
 268         return ERROR_OK;
 269 }
 270
 271 int log_remove_callback(log_callback_fn fn, void *priv)
 272 {
 273         log_callback_t *cb, **p;
 274
 275         for (p = &log_callbacks; (cb = *p); p = &(*p)->next)
 276         {
 277                 if (cb->fn == fn && cb->priv == priv)
 278                 {
 279                         *p = cb->next;
 280                         free(cb);
 281                         return ERROR_OK;
 282                 }
 283         }
 284
 285         /* no such item */
 286         return ERROR_INVALID_ARGUMENTS;
 287 }
 288
 289 /* return allocated string w/printf() result */
 290 char *alloc_vprintf(const char *fmt, va_list ap)
 291 {
 292         /* no buffer at the beginning, force realloc to do the job */
 293         char *string = NULL;
 294
 295         /* start with buffer size suitable for typical messages */
 296         int size = 128;
 297
 298         for (;;)
 299         {
 300                 char *t = string;
 301                 va_list ap_copy;
 302                 int ret;
 303                 string = realloc(string, size);
 304                 if (string == NULL)
 305                 {
 306                         if (t != NULL)
 307                                 free(t);
 308                         return NULL;
 309                 }
 310
 311                 va_copy(ap_copy, ap);
 312
 313                 ret = vsnprintf(string, size, fmt, ap_copy);
 314                 /* NB! The result of the vsnprintf() might be an *EMPTY* string! */
 315                 if ((ret >= 0) && ((ret + 1) < size))
 316                         break;
 317
 318                 /* there was just enough or not enough space, allocate more in the next round */
 319                 size *= 2; /* double the buffer size */
 320         }
 321
 322         /* the returned buffer is by principle guaranteed to be at least one character longer */
 323         return string;
 324 }
 325
 326 char *alloc_printf(const char *format, ...)
 327 {
 328         char *string;
 329         va_list ap;
 330         va_start(ap, format);
 331         string = alloc_vprintf(format, ap);
 332         va_end(ap);
 333         return string;
 334 }
 335
 336 /* Code must return to the server loop before 1000ms has returned or invoke
 337  * this function.
 338  *
 339  * The GDB connection will time out if it spends >2000ms and you'll get nasty
 340  * error messages from GDB:
 341  *
 342  * Ignoring packet error, continuing...
 343  * Reply contains invalid hex digit 116
 344  *
 345  * While it is possible use "set remotetimeout" to more than the default 2000ms
 346  * in GDB, OpenOCD guarantees that it sends keep-alive packages on the
 347  * GDB protocol and it is a bug in OpenOCD not to either return to the server
 348  * loop or invoke keep_alive() every 1000ms.
 349  *
 350  * This function will send a keep alive packet if >500ms has passed since last time
 351  * it was invoked.
 352  *
 353  */
 354 void keep_alive()
 355 {
 356         current_time=timeval_ms();
 357         if (current_time-last_time>1000)
 358         {
 359                 LOG_WARNING("keep_alive() was not invoked in the 1000ms timelimit. GDB alive packet not sent! (%d)", current_time-last_time);
 360                 last_time=current_time;
 361         } else if (current_time-last_time>500)
 362         {
 363                 /* this will keep the GDB connection alive */
 364                 LOG_USER_N("%s", "");
 365                 last_time=current_time;
 366         }
 367 }
 368
 369 /* reset keep alive timer without sending message */
 370 void kept_alive()
 371 {
 372         current_time=timeval_ms();
 373         last_time=current_time;
 374 }