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