helper: constify log_strings
[openocd.git] / src / helper / log.c
1 /***************************************************************************
2 * Copyright (C) 2005 by Dominic Rath *
3 * Dominic.Rath@gmx.de *
4 * *
5 * Copyright (C) 2007-2010 √ė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 * 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA. *
25 ***************************************************************************/
26
27 #ifdef HAVE_CONFIG_H
28 #include "config.h"
29 #endif
30
31 #include "time_support.h"
32 /* @todo the inclusion of server.h here is a layering violation */
33 #include <server/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 struct log_callback *log_callbacks;
49
50 static long long last_time;
51 static long long current_time;
52
53 static long long start;
54
55 static const char * const log_strings[5] = {
56 "User : ",
57 "Error: ",
58 "Warn : ", /* want a space after each colon, all same width, colons aligned */
59 "Info : ",
60 "Debug: "
61 };
62
63 static int count;
64
65 static struct store_log_forward *log_head;
66 static int log_forward_count;
67
68 struct store_log_forward {
69 struct store_log_forward *next;
70 const char *file;
71 int line;
72 const char *function;
73 const char *string;
74 };
75
76 /* either forward the log to the listeners or store it for possible forwarding later */
77 static void log_forward(const char *file, unsigned line, const char *function, const char *string)
78 {
79 if (log_forward_count == 0) {
80 struct log_callback *cb, *next;
81 cb = log_callbacks;
82 /* DANGER!!!! the log callback can remove itself!!!! */
83 while (cb) {
84 next = cb->next;
85 cb->fn(cb->priv, file, line, function, string);
86 cb = next;
87 }
88 } else {
89 struct store_log_forward *log = malloc(sizeof(struct store_log_forward));
90 log->file = strdup(file);
91 log->line = line;
92 log->function = strdup(function);
93 log->string = strdup(string);
94 log->next = NULL;
95 if (log_head == NULL)
96 log_head = log;
97 else {
98 /* append to tail */
99 struct store_log_forward *t;
100 t = log_head;
101 while (t->next != NULL)
102 t = t->next;
103 t->next = log;
104 }
105 }
106 }
107
108 /* The log_puts() serves to somewhat different goals:
109 *
110 * - logging
111 * - feeding low-level info to the user in GDB or Telnet
112 *
113 * The latter dictates that strings without newline are not logged, lest there
114 * will be *MANY log lines when sending one char at the time(e.g.
115 * target_request.c).
116 *
117 */
118 static void log_puts(enum log_levels level,
119 const char *file,
120 int line,
121 const char *function,
122 const char *string)
123 {
124 char *f;
125 if (level == LOG_LVL_OUTPUT) {
126 /* do not prepend any headers, just print out what we were given and return */
127 fputs(string, log_output);
128 fflush(log_output);
129 return;
130 }
131
132 f = strrchr(file, '/');
133 if (f != NULL)
134 file = f + 1;
135
136 if (strlen(string) > 0) {
137 if (debug_level >= LOG_LVL_DEBUG) {
138 /* print with count and time information */
139 int t = (int)(timeval_ms()-start);
140 #ifdef _DEBUG_FREE_SPACE_
141 struct mallinfo info;
142 info = mallinfo();
143 #endif
144 fprintf(log_output, "%s%d %d %s:%d %s()"
145 #ifdef _DEBUG_FREE_SPACE_
146 " %d"
147 #endif
148 ": %s", log_strings[level + 1], count, t, file, line, function,
149 #ifdef _DEBUG_FREE_SPACE_
150 info.fordblks,
151 #endif
152 string);
153 } else {
154 /* if we are using gdb through pipes then we do not want any output
155 * to the pipe otherwise we get repeated strings */
156 fprintf(log_output, "%s%s",
157 (level > LOG_LVL_USER) ? log_strings[level + 1] : "", string);
158 }
159 } else {
160 /* Empty strings are sent to log callbacks to keep e.g. gdbserver alive, here we do
161 *nothing. */
162 }
163
164 fflush(log_output);
165
166 /* Never forward LOG_LVL_DEBUG, too verbose and they can be found in the log if need be */
167 if (level <= LOG_LVL_INFO)
168 log_forward(file, line, function, string);
169 }
170
171 void log_printf(enum log_levels level,
172 const char *file,
173 unsigned line,
174 const char *function,
175 const char *format,
176 ...)
177 {
178 char *string;
179 va_list ap;
180
181 count++;
182 if (level > debug_level)
183 return;
184
185 va_start(ap, format);
186
187 string = alloc_vprintf(format, ap);
188 if (string != NULL) {
189 log_puts(level, file, line, function, string);
190 free(string);
191 }
192
193 va_end(ap);
194 }
195
196 void log_printf_lf(enum log_levels level,
197 const char *file,
198 unsigned line,
199 const char *function,
200 const char *format,
201 ...)
202 {
203 char *string;
204 va_list ap;
205
206 count++;
207 if (level > debug_level)
208 return;
209
210 va_start(ap, format);
211
212 string = alloc_vprintf(format, ap);
213 if (string != NULL) {
214 strcat(string, "\n"); /* alloc_vprintf guaranteed the buffer to be at least one
215 *char longer */
216 log_puts(level, file, line, function, string);
217 free(string);
218 }
219
220 va_end(ap);
221 }
222
223 COMMAND_HANDLER(handle_debug_level_command)
224 {
225 if (CMD_ARGC == 1) {
226 int new_level;
227 COMMAND_PARSE_NUMBER(int, CMD_ARGV[0], new_level);
228 if ((new_level > LOG_LVL_DEBUG) || (new_level < LOG_LVL_SILENT)) {
229 LOG_ERROR("level must be between %d and %d", LOG_LVL_SILENT, LOG_LVL_DEBUG);
230 return ERROR_COMMAND_SYNTAX_ERROR;
231 }
232 debug_level = new_level;
233 } else if (CMD_ARGC > 1)
234 return ERROR_COMMAND_SYNTAX_ERROR;
235
236 command_print(CMD_CTX, "debug_level: %i", debug_level);
237
238 return ERROR_OK;
239 }
240
241 COMMAND_HANDLER(handle_log_output_command)
242 {
243 if (CMD_ARGC == 1) {
244 FILE *file = fopen(CMD_ARGV[0], "w");
245
246 if (file)
247 log_output = file;
248 }
249
250 return ERROR_OK;
251 }
252
253 static struct command_registration log_command_handlers[] = {
254 {
255 .name = "log_output",
256 .handler = handle_log_output_command,
257 .mode = COMMAND_ANY,
258 .help = "redirect logging to a file (default: stderr)",
259 .usage = "file_name",
260 },
261 {
262 .name = "debug_level",
263 .handler = handle_debug_level_command,
264 .mode = COMMAND_ANY,
265 .help = "Sets the verbosity level of debugging output. "
266 "0 shows errors only; 1 adds warnings; "
267 "2 (default) adds other info; 3 adds debugging.",
268 .usage = "number",
269 },
270 COMMAND_REGISTRATION_DONE
271 };
272
273 int log_register_commands(struct command_context *cmd_ctx)
274 {
275 return register_commands(cmd_ctx, NULL, log_command_handlers);
276 }
277
278 void log_init(void)
279 {
280 /* set defaults for daemon configuration,
281 * if not set by cmdline or cfgfile */
282 if (debug_level == -1)
283 debug_level = LOG_LVL_INFO;
284
285 char *debug_env = getenv("OPENOCD_DEBUG_LEVEL");
286 if (NULL != debug_env) {
287 int value;
288 int retval = parse_int(debug_env, &value);
289 if (ERROR_OK == retval &&
290 debug_level >= LOG_LVL_SILENT &&
291 debug_level <= LOG_LVL_DEBUG)
292 debug_level = value;
293 }
294
295 if (log_output == NULL)
296 log_output = stderr;
297
298 start = last_time = timeval_ms();
299 }
300
301 int set_log_output(struct command_context *cmd_ctx, FILE *output)
302 {
303 log_output = output;
304 return ERROR_OK;
305 }
306
307 /* add/remove log callback handler */
308 int log_add_callback(log_callback_fn fn, void *priv)
309 {
310 struct log_callback *cb;
311
312 /* prevent the same callback to be registered more than once, just for sure */
313 for (cb = log_callbacks; cb; cb = cb->next) {
314 if (cb->fn == fn && cb->priv == priv)
315 return ERROR_COMMAND_SYNTAX_ERROR;
316 }
317
318 /* alloc memory, it is safe just to return in case of an error, no need for the caller to
319 *check this */
320 cb = malloc(sizeof(struct log_callback));
321 if (cb == NULL)
322 return ERROR_BUF_TOO_SMALL;
323
324 /* add item to the beginning of the linked list */
325 cb->fn = fn;
326 cb->priv = priv;
327 cb->next = log_callbacks;
328 log_callbacks = cb;
329
330 return ERROR_OK;
331 }
332
333 int log_remove_callback(log_callback_fn fn, void *priv)
334 {
335 struct log_callback *cb, **p;
336
337 for (p = &log_callbacks; (cb = *p); p = &(*p)->next) {
338 if (cb->fn == fn && cb->priv == priv) {
339 *p = cb->next;
340 free(cb);
341 return ERROR_OK;
342 }
343 }
344
345 /* no such item */
346 return ERROR_COMMAND_SYNTAX_ERROR;
347 }
348
349 /* return allocated string w/printf() result */
350 char *alloc_vprintf(const char *fmt, va_list ap)
351 {
352 va_list ap_copy;
353 int len;
354 char *string;
355
356 /* determine the length of the buffer needed */
357 va_copy(ap_copy, ap);
358 len = vsnprintf(NULL, 0, fmt, ap_copy);
359 va_end(ap_copy);
360
361 /* allocate and make room for terminating zero. */
362 /* FIXME: The old version always allocated at least one byte extra and
363 * other code depend on that. They should be probably be fixed, but for
364 * now reserve the extra byte. */
365 string = malloc(len + 2);
366 if (string == NULL)
367 return NULL;
368
369 /* do the real work */
370 vsnprintf(string, len + 1, fmt, ap);
371
372 return string;
373 }
374
375 char *alloc_printf(const char *format, ...)
376 {
377 char *string;
378 va_list ap;
379 va_start(ap, format);
380 string = alloc_vprintf(format, ap);
381 va_end(ap);
382 return string;
383 }
384
385 /* Code must return to the server loop before 1000ms has returned or invoke
386 * this function.
387 *
388 * The GDB connection will time out if it spends >2000ms and you'll get nasty
389 * error messages from GDB:
390 *
391 * Ignoring packet error, continuing...
392 * Reply contains invalid hex digit 116
393 *
394 * While it is possible use "set remotetimeout" to more than the default 2000ms
395 * in GDB, OpenOCD guarantees that it sends keep-alive packages on the
396 * GDB protocol and it is a bug in OpenOCD not to either return to the server
397 * loop or invoke keep_alive() every 1000ms.
398 *
399 * This function will send a keep alive packet if >500ms has passed since last time
400 * it was invoked.
401 *
402 * Note that this function can be invoked often, so it needs to be relatively
403 * fast when invoked more often than every 500ms.
404 *
405 */
406 void keep_alive()
407 {
408 current_time = timeval_ms();
409 if (current_time-last_time > 1000) {
410 extern int gdb_actual_connections;
411
412 if (gdb_actual_connections)
413 LOG_WARNING("keep_alive() was not invoked in the "
414 "1000ms timelimit. GDB alive packet not "
415 "sent! (%lld). Workaround: increase "
416 "\"set remotetimeout\" in GDB",
417 current_time-last_time);
418 else
419 LOG_DEBUG("keep_alive() was not invoked in the "
420 "1000ms timelimit (%lld). This may cause "
421 "trouble with GDB connections.",
422 current_time-last_time);
423 }
424 if (current_time-last_time > 500) {
425 /* this will keep the GDB connection alive */
426 LOG_USER_N("%s", "");
427
428 /* DANGER!!!! do not add code to invoke e.g. target event processing,
429 * jim timer processing, etc. it can cause infinite recursion +
430 * jim event callbacks need to happen at a well defined time,
431 * not anywhere keep_alive() is invoked.
432 *
433 * These functions should be invoked at a well defined spot in server.c
434 */
435
436 last_time = current_time;
437 }
438 }
439
440 /* reset keep alive timer without sending message */
441 void kept_alive()
442 {
443 current_time = timeval_ms();
444 last_time = current_time;
445 }
446
447 /* if we sleep for extended periods of time, we must invoke keep_alive() intermittantly */
448 void alive_sleep(uint64_t ms)
449 {
450 uint64_t napTime = 10;
451 for (uint64_t i = 0; i < ms; i += napTime) {
452 uint64_t sleep_a_bit = ms - i;
453 if (sleep_a_bit > napTime)
454 sleep_a_bit = napTime;
455
456 usleep(sleep_a_bit * 1000);
457 keep_alive();
458 }
459 }
460
461 void busy_sleep(uint64_t ms)
462 {
463 uint64_t then = timeval_ms();
464 while (timeval_ms() - then < ms) {
465 /*
466 * busy wait
467 */
468 }
469 }