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