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                         /* print human readable output */
 111                         fprintf(log_output, "%s%s",
 112                                         (level > LOG_LVL_USER)?log_strings[level+1]:"", string);
 113                 }
 114         } else
 115         {
 116                 /* only entire lines are logged. Otherwise it's
 117                  * single chars intended for the log callbacks. */
 118         }
 119
 120         fflush(log_output);
 121
 122         /* Never forward LOG_LVL_DEBUG, too verbose and they can be found in the log if need be */
 123         if (level <= LOG_LVL_INFO)
 124         {
 125                 log_callback_t *cb, *next;
 126                 cb = log_callbacks;
 127                 /* DANGER!!!! the log callback can remove itself!!!! */
 128                 while (cb)
 129                 {
 130                         next=cb->next;
 131                         cb->fn(cb->priv, file, line, function, string);
 132                         cb=next;
 133                 }
 134         }
 135 }
 136
 137 void log_printf(enum log_levels level, const char *file, int line, const char *function, const char *format, ...)
 138 {
 139         char *string;
 140         va_list ap;
 141
 142         count++;
 143         if (level > debug_level)
 144                 return;
 145
 146         va_start(ap, format);
 147
 148         string = alloc_vprintf(format, ap);
 149         if (string != NULL)
 150         {
 151                 log_puts(level, file, line, function, string);
 152                 free(string);
 153         }
 154
 155         va_end(ap);
 156 }
 157
 158 void log_printf_lf(enum log_levels level, const char *file, int line, const char *function, const char *format, ...)
 159 {
 160         char *string;
 161         va_list ap;
 162
 163         count++;
 164         if (level > debug_level)
 165                 return;
 166
 167         va_start(ap, format);
 168
 169         string = alloc_vprintf(format, ap);
 170         if (string != NULL)
 171         {
 172                 strcat(string, "\n"); /* alloc_vprintf guaranteed the buffer to be at least one char longer */
 173                 log_puts(level, file, line, function, string);
 174                 free(string);
 175         }
 176
 177         va_end(ap);
 178 }
 179
 180 /* change the current debug level on the fly
 181  * 0: only ERRORS
 182  * 1: + WARNINGS
 183  * 2: + INFORMATIONAL MSGS
 184  * 3: + DEBUG MSGS
 185  */
 186 int handle_debug_level_command(struct command_context_s *cmd_ctx, char *cmd, char **args, int argc)
 187 {
 188         if (argc == 0)
 189                 command_print(cmd_ctx, "debug_level: %i", debug_level);
 190
 191         if (argc > 0)
 192                 debug_level = strtoul(args[0], NULL, 0);
 193
 194         if (debug_level < 0)
 195                 debug_level = 0;
 196
 197         if (debug_level > 3)
 198                 debug_level = 3;
 199
 200         return ERROR_OK;
 201 }
 202
 203 int handle_log_output_command(struct command_context_s *cmd_ctx, char *cmd, char **args, int argc)
 204 {
 205         if (argc == 1)
 206         {
 207                 FILE* file = fopen(args[0], "w");
 208
 209                 if (file)
 210                 {
 211                         log_output = file;
 212                 }
 213         }
 214
 215         return ERROR_OK;
 216 }
 217
 218 int log_register_commands(struct command_context_s *cmd_ctx)
 219 {
 220         start = timeval_ms();
 221         register_command(cmd_ctx, NULL, "log_output", handle_log_output_command,
 222                 COMMAND_ANY, "redirect logging to <file> (default: stderr)");
 223         register_command(cmd_ctx, NULL, "debug_level", handle_debug_level_command,
 224                 COMMAND_ANY, "adjust debug level <0-3>");
 225
 226         return ERROR_OK;
 227 }
 228
 229 int log_init(struct command_context_s *cmd_ctx)
 230 {
 231         /* set defaults for daemon configuration, if not set by cmdline or cfgfile */
 232         if (debug_level == -1)
 233                 debug_level = LOG_LVL_INFO;
 234
 235         if (log_output == NULL)
 236         {
 237                 log_output = stderr;
 238         }
 239
 240         start=last_time=timeval_ms();
 241
 242         return ERROR_OK;
 243 }
 244
 245 int set_log_output(struct command_context_s *cmd_ctx, FILE *output)
 246 {
 247         log_output = output;
 248         return ERROR_OK;
 249 }
 250
 251 /* add/remove log callback handler */
 252 int log_add_callback(log_callback_fn fn, void *priv)
 253 {
 254         log_callback_t *cb;
 255
 256         /* prevent the same callback to be registered more than once, just for sure */
 257         for (cb = log_callbacks; cb; cb = cb->next)
 258         {
 259                 if (cb->fn == fn && cb->priv == priv)
 260                         return ERROR_INVALID_ARGUMENTS;
 261         }
 262
 263         /* alloc memory, it is safe just to return in case of an error, no need for the caller to check this */
 264         if ((cb = malloc(sizeof(log_callback_t))) == NULL)
 265                 return ERROR_BUF_TOO_SMALL;
 266
 267         /* add item to the beginning of the linked list */
 268         cb->fn = fn;
 269         cb->priv = priv;
 270         cb->next = log_callbacks;
 271         log_callbacks = cb;
 272
 273         return ERROR_OK;
 274 }
 275
 276 int log_remove_callback(log_callback_fn fn, void *priv)
 277 {
 278         log_callback_t *cb, **p;
 279
 280         for (p = &log_callbacks; (cb = *p); p = &(*p)->next)
 281         {
 282                 if (cb->fn == fn && cb->priv == priv)
 283                 {
 284                         *p = cb->next;
 285                         free(cb);
 286                         return ERROR_OK;
 287                 }
 288         }
 289
 290         /* no such item */
 291         return ERROR_INVALID_ARGUMENTS;
 292 }
 293
 294 /* return allocated string w/printf() result */
 295 char *alloc_vprintf(const char *fmt, va_list ap)
 296 {
 297         /* no buffer at the beginning, force realloc to do the job */
 298         char *string = NULL;
 299
 300         /* start with buffer size suitable for typical messages */
 301         int size = 128;
 302
 303         for (;;)
 304         {
 305                 char *t = string;
 306                 va_list ap_copy;
 307                 int ret;
 308                 string = realloc(string, size);
 309                 if (string == NULL)
 310                 {
 311                         if (t != NULL)
 312                                 free(t);
 313                         return NULL;
 314                 }
 315
 316                 va_copy(ap_copy, ap);
 317
 318                 ret = vsnprintf(string, size, fmt, ap_copy);
 319                 /* NB! The result of the vsnprintf() might be an *EMPTY* string! */
 320                 if ((ret >= 0) && ((ret + 1) < size))
 321                         break;
 322
 323                 /* there was just enough or not enough space, allocate more in the next round */
 324                 size *= 2; /* double the buffer size */
 325         }
 326
 327         /* the returned buffer is by principle guaranteed to be at least one character longer */
 328         return string;
 329 }
 330
 331 char *alloc_printf(const char *format, ...)
 332 {
 333         char *string;
 334         va_list ap;
 335         va_start(ap, format);
 336         string = alloc_vprintf(format, ap);
 337         va_end(ap);
 338         return string;
 339 }
 340
 341 /* Code must return to the server loop before 1000ms has returned or invoke
 342  * this function.
 343  *
 344  * The GDB connection will time out if it spends >2000ms and you'll get nasty
 345  * error messages from GDB:
 346  *
 347  * Ignoring packet error, continuing...
 348  * Reply contains invalid hex digit 116
 349  *
 350  * While it is possible use "set remotetimeout" to more than the default 2000ms
 351  * in GDB, OpenOCD guarantees that it sends keep-alive packages on the
 352  * GDB protocol and it is a bug in OpenOCD not to either return to the server
 353  * loop or invoke keep_alive() every 1000ms.
 354  *
 355  * This function will send a keep alive packet if >500ms has passed since last time
 356  * it was invoked.
 357  *
 358  */
 359 void keep_alive()
 360 {
 361         current_time=timeval_ms();
 362         if (current_time-last_time>1000)
 363         {
 364                 LOG_WARNING("BUG: keep_alive() was not invoked in the 1000ms timelimit. GDB alive packet not sent! (%lld)", current_time-last_time);
 365                 last_time=current_time;
 366         } else if (current_time-last_time>500)
 367         {
 368                 /* this will keep the GDB connection alive */
 369                 LOG_USER_N("%s", "");
 370                 last_time=current_time;
 371         }
 372
 373         /* also process TCL events (we have to do this from 'log.c' since its
 374          * keep_alive() is the only routine guaranteed to be called at least
 375          * once per second :( */
 376         process_jim_events ();
 377 }
 378
 379 /* reset keep alive timer without sending message */
 380 void kept_alive()
 381 {
 382         current_time=timeval_ms();
 383         last_time=current_time;
 384 }