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