src/helper/log.c

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