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