log.c 9.05 KB
Newer Older
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
/***************************************************************************
 *   Copyright (C) 2005 by Dominic Rath                                    *
 *   Dominic.Rath@gmx.de                                                   *
 *                                                                         *
 *   This program is free software; you can redistribute it and/or modify  *
 *   it under the terms of the GNU General Public License as published by  *
 *   the Free Software Foundation; either version 2 of the License, or     *
 *   (at your option) any later version.                                   *
 *                                                                         *
 *   This program is distributed in the hope that it will be useful,       *
 *   but WITHOUT ANY WARRANTY; without even the implied warranty of        *
 *   MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the         *
 *   GNU General Public License for more details.                          *
 *                                                                         *
 *   You should have received a copy of the GNU General Public License     *
 *   along with this program; if not, write to the                         *
 *   Free Software Foundation, Inc.,                                       *
 *   59 Temple Place - Suite 330, Boston, MA  02111-1307, USA.             *
 ***************************************************************************/
#ifdef HAVE_CONFIG_H
#include "config.h"
#endif

#include "log.h"
#include "configuration.h"
oharboe's avatar
oharboe committed
26
#include "time_support.h"
27
28
29
30
31

#include <stdio.h>
#include <stdlib.h>
#include <string.h>
#include <stdarg.h>
32
33
34

#define PRINT_MEM() 0
#if PRINT_MEM()
35
#include <malloc.h>
36
#endif
37
38
39
40
41
42

int debug_level = -1;

static FILE* log_output;
static log_callback_t *log_callbacks = NULL;

43
44
45
static long long last_time;
static long long current_time;

46
static long long start;
47
48
49
50
51
52
53
54
55
56

static char *log_strings[5] =
{
	"User:   ",
	"Error:  ",
	"Warning:",
	"Info:   ",
	"Debug:  "
};

57
58
static int count = 0;

oharboe's avatar
oharboe committed
59
/* The log_puts() serves to somewhat different goals:
60
61
62
63
64
65
66
67
68
 * 
 * - logging
 * - feeding low-level info to the user in GDB or Telnet
 * 
 * The latter dictates that strings without newline are not logged, lest there
 * will be *MANY log lines when sending one char at the time(e.g. 
 * target_request.c).
 * 
 */
69
static void log_puts(enum log_levels level, const char *file, int line, const char *function, const char *string)
70
{
oharboe's avatar
oharboe committed
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
77
78
79
		fflush(log_output);
		return;
	}

oharboe's avatar
oharboe committed
80
	f = strrchr(file, '/');
81
82
83
	if (f != NULL)
		file = f + 1;

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
92
			struct mallinfo info;
			info = mallinfo();
93
94
#endif
			fprintf(log_output, "%s %d %d %s:%d %s()"
95
#if PRINT_MEM()
96
97
98
					" %d"
#endif
					": %s", log_strings[level+1], count, t, file, line, function, 
99
#if PRINT_MEM()
100
101
102
					info.fordblks,
#endif
					string);
103
104
105
106
107
108
109
		}
		else
		{
			/* do not print count and time */
			fprintf(log_output, "%s %s:%d %s(): %s", log_strings[level+1], file, line, function, string);
		}
	} else
110
	{
111
112
		/* only entire lines are logged. Otherwise it's 
		 * single chars intended for the log callbacks. */
113
114
115
	}

	fflush(log_output);
oharboe's avatar
oharboe committed
116
	
117
118
	/* Never forward LOG_LVL_DEBUG, too verbose and they can be found in the log if need be */
	if (level <= LOG_LVL_INFO)
119
	{
120
121
122
123
		log_callback_t *cb, *next;
		cb = log_callbacks;
		/* DANGER!!!! the log callback can remove itself!!!! */
		while (cb)
124
		{
125
			next=cb->next;
126
			cb->fn(cb->priv, file, line, function, string);
127
			cb=next;
128
129
130
131
		}
	}
}

132
133
void log_printf(enum log_levels level, const char *file, int line, const char *function, const char *format, ...)
{
134
	char *string;
oharboe's avatar
oharboe committed
135
	va_list ap;
136

137
138
139
140
	count++;
	if (level > debug_level)
		return;

141
142
	va_start(ap, format);

oharboe's avatar
oharboe committed
143
	string = alloc_vprintf(format, ap);
144
145
146
147
148
	if (string != NULL)
	{
		log_puts(level, file, line, function, string);
		free(string);
	}
149
	
150
	va_end(ap);
151
152
}

153
void log_printf_lf(enum log_levels level, const char *file, int line, const char *function, const char *format, ...)
154
{
155
	char *string;
oharboe's avatar
oharboe committed
156
	va_list ap;
157

158
159
160
	count++;
	if (level > debug_level)
		return;
161
	
162
	va_start(ap, format);
163
	
oharboe's avatar
oharboe committed
164
	string = alloc_vprintf(format, ap);
165
166
	if (string != NULL)
	{
oharboe's avatar
oharboe committed
167
		strcat(string, "\n"); /* alloc_vprintf guaranteed the buffer to be at least one char longer */
168
169
170
		log_puts(level, file, line, function, string);
		free(string);
	}
171
	
172
	va_end(ap);
173
174
}

175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
/* change the current debug level on the fly
 * 0: only ERRORS
 * 1: + WARNINGS
 * 2: + INFORMATIONAL MSGS
 * 3: + DEBUG MSGS
 */
int handle_debug_level_command(struct command_context_s *cmd_ctx, char *cmd, char **args, int argc)
{
	if (argc == 0)
		command_print(cmd_ctx, "debug_level: %i", debug_level);

	if (argc > 0)
		debug_level = strtoul(args[0], NULL, 0);

	if (debug_level < 0)
		debug_level = 0;

	if (debug_level > 3)
		debug_level = 3;

	return ERROR_OK;
}

int handle_log_output_command(struct command_context_s *cmd_ctx, char *cmd, char **args, int argc)
{
	if (argc == 1)
	{
		FILE* file = fopen(args[0], "w");
oharboe's avatar
oharboe committed
203
		
204
205
206
207
208
209
210
211
212
213
214
		if (file)
		{
			log_output = file;
		}
	}

	return ERROR_OK;
}

int log_register_commands(struct command_context_s *cmd_ctx)
{
215
	start = timeval_ms();
216
217
218
219
220
221
222
223
224
225
226
227
	register_command(cmd_ctx, NULL, "log_output", handle_log_output_command,
		COMMAND_ANY, "redirect logging to <file> (default: stderr)");
	register_command(cmd_ctx, NULL, "debug_level", handle_debug_level_command,
		COMMAND_ANY, "adjust debug level <0-3>");

	return ERROR_OK;
}

int log_init(struct command_context_s *cmd_ctx)
{
	/* set defaults for daemon configuration, if not set by cmdline or cfgfile */
	if (debug_level == -1)
228
		debug_level = LOG_LVL_INFO;
oharboe's avatar
oharboe committed
229
	
230
231
232
233
	if (log_output == NULL)
	{
		log_output = stderr;
	}
oharboe's avatar
oharboe committed
234
	
235
236
	start=last_time=timeval_ms();
	
237
238
	return ERROR_OK;
}
oharboe's avatar
oharboe committed
239
	
240
241
242
243
244
245
246
247
248
249
250
251
252
253
254
255
256
257
258
259
260
261
262
263
264
265
266
267
268
269
270
271
272
273
274
int set_log_output(struct command_context_s *cmd_ctx, FILE *output)
{
	log_output = output;
	return ERROR_OK;
}

/* add/remove log callback handler */
int log_add_callback(log_callback_fn fn, void *priv)
{
	log_callback_t *cb;

	/* prevent the same callback to be registered more than once, just for sure */
	for (cb = log_callbacks; cb; cb = cb->next)
	{
		if (cb->fn == fn && cb->priv == priv)
			return ERROR_INVALID_ARGUMENTS;
	}

	/* alloc memory, it is safe just to return in case of an error, no need for the caller to check this */
	if ((cb = malloc(sizeof(log_callback_t))) == NULL)
		return ERROR_BUF_TOO_SMALL;

	/* add item to the beginning of the linked list */
	cb->fn = fn;
	cb->priv = priv;
	cb->next = log_callbacks;
	log_callbacks = cb;

	return ERROR_OK;
}

int log_remove_callback(log_callback_fn fn, void *priv)
{
	log_callback_t *cb, **p;

ntfreak's avatar
ntfreak committed
275
	for (p = &log_callbacks; (cb = *p); p = &(*p)->next)
276
	{
oharboe's avatar
oharboe committed
277
278
279
		if (cb->fn == fn && cb->priv == priv)
		{
			*p = cb->next;
280
281
282
283
284
285
286
287
288
289
			free(cb);
			return ERROR_OK;
		}
	}

	/* no such item */
	return ERROR_INVALID_ARGUMENTS;
}

/* return allocated string w/printf() result */
oharboe's avatar
oharboe committed
290
char *alloc_vprintf(const char *fmt, va_list ap)
291
{
292
	/* no buffer at the beginning, force realloc to do the job */
293
	char *string = NULL;
oharboe's avatar
oharboe committed
294
	
oharboe's avatar
oharboe committed
295
296
	/* start with buffer size suitable for typical messages */
	int size = 128;
297

298
299
	for (;;)
	{
oharboe's avatar
oharboe committed
300
		char *t = string;
oharboe's avatar
oharboe committed
301
302
		va_list ap_copy;
		int ret;
oharboe's avatar
oharboe committed
303
304
305
306
307
308
309
		string = realloc(string, size);
		if (string == NULL)
		{
			if (t != NULL)
				free(t);
			return NULL;
		}
310

oharboe's avatar
oharboe committed
311
		va_copy(ap_copy, ap);
312
313

		ret = vsnprintf(string, size, fmt, ap_copy);
oharboe's avatar
oharboe committed
314
315
		/* NB! The result of the vsnprintf() might be an *EMPTY* string! */
		if ((ret >= 0) && ((ret + 1) < size))
316
317
			break;

oharboe's avatar
oharboe committed
318
		/* there was just enough or not enough space, allocate more in the next round */
oharboe's avatar
oharboe committed
319
		size *= 2; /* double the buffer size */
320
	}
321
322
	
	/* the returned buffer is by principle guaranteed to be at least one character longer */
oharboe's avatar
oharboe committed
323
	return string;
324
}
oharboe's avatar
oharboe committed
325
326
327
328
329
330
331
332
333
334

char *alloc_printf(const char *format, ...)
{
	char *string;
	va_list ap;
	va_start(ap, format);
	string = alloc_vprintf(format, ap);
	va_end(ap);
	return string;
}
335
336
337
338
339
340
341
342
343
344
345
346
347
348
349
350
351
352
353
354
355
356
357
358
359
360
361
362
363
364
365
366
367
368
369
370
371
372
373
374

/* Code must return to the server loop before 1000ms has returned or invoke
 * this function.
 * 
 * The GDB connection will time out if it spends >2000ms and you'll get nasty
 * error messages from GDB:
 * 
 * Ignoring packet error, continuing...
 * Reply contains invalid hex digit 116
 *
 * While it is possible use "set remotetimeout" to more than the default 2000ms
 * in GDB, OpenOCD guarantees that it sends keep-alive packages on the
 * GDB protocol and it is a bug in OpenOCD not to either return to the server
 * loop or invoke keep_alive() every 1000ms.
 * 
 * This function will send a keep alive packet if >500ms has passed since last time
 * it was invoked.
 * 
 */
void keep_alive()
{
	current_time=timeval_ms();
	if (current_time-last_time>1000)
	{
		LOG_WARNING("keep_alive() was not invoked in the 1000ms timelimit. GDB alive packet not sent! (%d)", current_time-last_time); 
		last_time=current_time;
	} else if (current_time-last_time>500)
	{
		/* this will keep the GDB connection alive */
		LOG_USER_N("%s", "");
		last_time=current_time;
	}
}

/* reset keep alive timer without sending message */
void kept_alive()
{
	current_time=timeval_ms();
	last_time=current_time;
}