src/helper/log.c

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