xref: /dpdk/lib/log/log.c (revision 036f72d07249aa36c2d2d61bdaf84a492044d0d9)
1 /* SPDX-License-Identifier: BSD-3-Clause
2  * Copyright(c) 2010-2014 Intel Corporation
3  */
4 
5 #include <stdbool.h>
6 #include <stdio.h>
7 #include <stdint.h>
8 #include <stdarg.h>
9 #include <stdlib.h>
10 #include <string.h>
11 #include <errno.h>
12 #include <regex.h>
13 #include <fnmatch.h>
14 #include <sys/queue.h>
15 #include <unistd.h>
16 
17 #include <rte_common.h>
18 #include <rte_log.h>
19 #include <rte_per_lcore.h>
20 
21 #ifdef RTE_EXEC_ENV_WINDOWS
22 #include <rte_os_shim.h>
23 #endif
24 
25 #include "log_internal.h"
26 #include "log_private.h"
27 
28 struct rte_log_dynamic_type {
29 	const char *name;
30 	uint32_t loglevel;
31 };
32 
33 /* Note: same as vfprintf() */
34 typedef int (*log_print_t)(FILE *f, const char *fmt, va_list ap);
35 
36 /** The rte_log structure. */
37 static struct rte_logs {
38 	uint32_t type;  /**< Bitfield with enabled logs. */
39 	uint32_t level; /**< Log level. */
40 	FILE *file;     /**< Output file set by rte_openlog_stream, or NULL. */
41 	log_print_t print_func;
42 	size_t dynamic_types_len;
43 	struct rte_log_dynamic_type *dynamic_types;
44 } rte_logs = {
45 	.type = UINT32_MAX,
46 	.level = RTE_LOG_DEBUG,
47 	.print_func = vfprintf,
48 };
49 
50 struct rte_eal_opt_loglevel {
51 	/** Next list entry */
52 	TAILQ_ENTRY(rte_eal_opt_loglevel) next;
53 	/** Compiled regular expression obtained from the option */
54 	regex_t re_match;
55 	/** Globbing pattern option */
56 	char *pattern;
57 	/** Log level value obtained from the option */
58 	uint32_t level;
59 };
60 
61 TAILQ_HEAD(rte_eal_opt_loglevel_list, rte_eal_opt_loglevel);
62 
63 /** List of valid EAL log level options */
64 static struct rte_eal_opt_loglevel_list opt_loglevel_list =
65 	TAILQ_HEAD_INITIALIZER(opt_loglevel_list);
66 
67 /**
68  * This global structure stores some information about the message
69  * that is currently being processed by one lcore
70  */
71 struct log_cur_msg {
72 	uint32_t loglevel; /**< log level - see rte_log.h */
73 	uint32_t logtype;  /**< log type  - see rte_log.h */
74 };
75 
76  /* per core log */
77 static RTE_DEFINE_PER_LCORE(struct log_cur_msg, log_cur_msg);
78 
79 /* Change the stream that will be used by logging system */
80 int
81 rte_openlog_stream(FILE *f)
82 {
83 	rte_logs.file = f;
84 	rte_logs.print_func = vfprintf;
85 	return 0;
86 }
87 
88 FILE *
89 rte_log_get_stream(void)
90 {
91 	FILE *f = rte_logs.file;
92 
93 	return (f == NULL) ? stderr : f;
94 }
95 
96 /* Set global log level */
97 void
98 rte_log_set_global_level(uint32_t level)
99 {
100 	rte_logs.level = (uint32_t)level;
101 }
102 
103 /* Get global log level */
104 uint32_t
105 rte_log_get_global_level(void)
106 {
107 	return rte_logs.level;
108 }
109 
110 int
111 rte_log_get_level(uint32_t type)
112 {
113 	if (type >= rte_logs.dynamic_types_len)
114 		return -1;
115 
116 	return rte_logs.dynamic_types[type].loglevel;
117 }
118 
119 bool
120 rte_log_can_log(uint32_t logtype, uint32_t level)
121 {
122 	int log_level;
123 
124 	if (level > rte_log_get_global_level())
125 		return false;
126 
127 	log_level = rte_log_get_level(logtype);
128 	if (log_level < 0)
129 		return false;
130 
131 	if (level > (uint32_t)log_level)
132 		return false;
133 
134 	return true;
135 }
136 
137 static void
138 logtype_set_level(uint32_t type, uint32_t level)
139 {
140 	uint32_t current = rte_logs.dynamic_types[type].loglevel;
141 
142 	if (current != level) {
143 		rte_logs.dynamic_types[type].loglevel = level;
144 		RTE_LOG(DEBUG, EAL, "%s log level changed from %s to %s\n",
145 			rte_logs.dynamic_types[type].name == NULL ?
146 				"" : rte_logs.dynamic_types[type].name,
147 			eal_log_level2str(current),
148 			eal_log_level2str(level));
149 	}
150 }
151 
152 int
153 rte_log_set_level(uint32_t type, uint32_t level)
154 {
155 	if (type >= rte_logs.dynamic_types_len)
156 		return -1;
157 	if (level > RTE_LOG_MAX)
158 		return -1;
159 
160 	logtype_set_level(type, level);
161 
162 	return 0;
163 }
164 
165 /* set log level by regular expression */
166 int
167 rte_log_set_level_regexp(const char *regex, uint32_t level)
168 {
169 	regex_t r;
170 	size_t i;
171 
172 	if (level > RTE_LOG_MAX)
173 		return -1;
174 
175 	if (regcomp(&r, regex, 0) != 0)
176 		return -1;
177 
178 	for (i = 0; i < rte_logs.dynamic_types_len; i++) {
179 		if (rte_logs.dynamic_types[i].name == NULL)
180 			continue;
181 		if (regexec(&r, rte_logs.dynamic_types[i].name, 0,
182 				NULL, 0) == 0)
183 			logtype_set_level(i, level);
184 	}
185 
186 	regfree(&r);
187 
188 	return 0;
189 }
190 
191 /*
192  * Save the type string and the loglevel for later dynamic
193  * logtypes which may register later.
194  */
195 static int
196 log_save_level(uint32_t priority, const char *regex, const char *pattern)
197 {
198 	struct rte_eal_opt_loglevel *opt_ll = NULL;
199 
200 	opt_ll = malloc(sizeof(*opt_ll));
201 	if (opt_ll == NULL)
202 		goto fail;
203 
204 	opt_ll->level = priority;
205 
206 	if (regex) {
207 		opt_ll->pattern = NULL;
208 		if (regcomp(&opt_ll->re_match, regex, 0) != 0)
209 			goto fail;
210 	} else if (pattern) {
211 		opt_ll->pattern = strdup(pattern);
212 		if (opt_ll->pattern == NULL)
213 			goto fail;
214 	} else
215 		goto fail;
216 
217 	TAILQ_INSERT_HEAD(&opt_loglevel_list, opt_ll, next);
218 	return 0;
219 fail:
220 	free(opt_ll);
221 	return -1;
222 }
223 
224 int
225 eal_log_save_regexp(const char *regex, uint32_t level)
226 {
227 	return log_save_level(level, regex, NULL);
228 }
229 
230 /* set log level based on globbing pattern */
231 int
232 rte_log_set_level_pattern(const char *pattern, uint32_t level)
233 {
234 	size_t i;
235 
236 	if (level > RTE_LOG_MAX)
237 		return -1;
238 
239 	for (i = 0; i < rte_logs.dynamic_types_len; i++) {
240 		if (rte_logs.dynamic_types[i].name == NULL)
241 			continue;
242 
243 		if (fnmatch(pattern, rte_logs.dynamic_types[i].name, 0) == 0)
244 			logtype_set_level(i, level);
245 	}
246 
247 	return 0;
248 }
249 
250 int
251 eal_log_save_pattern(const char *pattern, uint32_t level)
252 {
253 	return log_save_level(level, NULL, pattern);
254 }
255 
256 /* get the current loglevel for the message being processed */
257 int rte_log_cur_msg_loglevel(void)
258 {
259 	return RTE_PER_LCORE(log_cur_msg).loglevel;
260 }
261 
262 /* get the current logtype for the message being processed */
263 int rte_log_cur_msg_logtype(void)
264 {
265 	return RTE_PER_LCORE(log_cur_msg).logtype;
266 }
267 
268 static int
269 log_lookup(const char *name)
270 {
271 	size_t i;
272 
273 	for (i = 0; i < rte_logs.dynamic_types_len; i++) {
274 		if (rte_logs.dynamic_types[i].name == NULL)
275 			continue;
276 		if (strcmp(name, rte_logs.dynamic_types[i].name) == 0)
277 			return i;
278 	}
279 
280 	return -1;
281 }
282 
283 static int
284 log_register(const char *name, uint32_t level)
285 {
286 	struct rte_log_dynamic_type *new_dynamic_types;
287 	int id;
288 
289 	id = log_lookup(name);
290 	if (id >= 0)
291 		return id;
292 
293 	new_dynamic_types = realloc(rte_logs.dynamic_types,
294 		sizeof(struct rte_log_dynamic_type) *
295 		(rte_logs.dynamic_types_len + 1));
296 	if (new_dynamic_types == NULL)
297 		return -ENOMEM;
298 	rte_logs.dynamic_types = new_dynamic_types;
299 
300 	id = rte_logs.dynamic_types_len;
301 	memset(&rte_logs.dynamic_types[id], 0,
302 		sizeof(rte_logs.dynamic_types[id]));
303 	rte_logs.dynamic_types[id].name = strdup(name);
304 	if (rte_logs.dynamic_types[id].name == NULL)
305 		return -ENOMEM;
306 	logtype_set_level(id, level);
307 
308 	rte_logs.dynamic_types_len++;
309 
310 	return id;
311 }
312 
313 /* register an extended log type */
314 int
315 rte_log_register(const char *name)
316 {
317 	return log_register(name, RTE_LOG_INFO);
318 }
319 
320 /* Register an extended log type and try to pick its level from EAL options */
321 int
322 rte_log_register_type_and_pick_level(const char *name, uint32_t level_def)
323 {
324 	struct rte_eal_opt_loglevel *opt_ll;
325 	uint32_t level = level_def;
326 
327 	TAILQ_FOREACH(opt_ll, &opt_loglevel_list, next) {
328 		if (opt_ll->level > RTE_LOG_MAX)
329 			continue;
330 
331 		if (opt_ll->pattern) {
332 			if (fnmatch(opt_ll->pattern, name, 0) == 0)
333 				level = opt_ll->level;
334 		} else {
335 			if (regexec(&opt_ll->re_match, name, 0, NULL, 0) == 0)
336 				level = opt_ll->level;
337 		}
338 	}
339 
340 	return log_register(name, level);
341 }
342 
343 struct logtype {
344 	uint32_t log_id;
345 	const char *logtype;
346 };
347 
348 static const struct logtype logtype_strings[] = {
349 	{RTE_LOGTYPE_EAL,        "lib.eal"},
350 
351 	{RTE_LOGTYPE_USER1,      "user1"},
352 	{RTE_LOGTYPE_USER2,      "user2"},
353 	{RTE_LOGTYPE_USER3,      "user3"},
354 	{RTE_LOGTYPE_USER4,      "user4"},
355 	{RTE_LOGTYPE_USER5,      "user5"},
356 	{RTE_LOGTYPE_USER6,      "user6"},
357 	{RTE_LOGTYPE_USER7,      "user7"},
358 	{RTE_LOGTYPE_USER8,      "user8"}
359 };
360 
361 /* Logging should be first initializer (before drivers and bus) */
362 RTE_INIT_PRIO(log_init, LOG)
363 {
364 	uint32_t i;
365 
366 	rte_log_set_global_level(RTE_LOG_DEBUG);
367 
368 	rte_logs.dynamic_types = calloc(RTE_LOGTYPE_FIRST_EXT_ID,
369 		sizeof(struct rte_log_dynamic_type));
370 	if (rte_logs.dynamic_types == NULL)
371 		return;
372 
373 	/* register legacy log types */
374 	for (i = 0; i < RTE_DIM(logtype_strings); i++) {
375 		rte_logs.dynamic_types[logtype_strings[i].log_id].name =
376 			strdup(logtype_strings[i].logtype);
377 		logtype_set_level(logtype_strings[i].log_id, RTE_LOG_INFO);
378 	}
379 
380 	rte_logs.dynamic_types_len = RTE_LOGTYPE_FIRST_EXT_ID;
381 }
382 
383 const char *
384 eal_log_level2str(uint32_t level)
385 {
386 	switch (level) {
387 	case 0: return "disabled";
388 	case RTE_LOG_EMERG: return "emergency";
389 	case RTE_LOG_ALERT: return "alert";
390 	case RTE_LOG_CRIT: return "critical";
391 	case RTE_LOG_ERR: return "error";
392 	case RTE_LOG_WARNING: return "warning";
393 	case RTE_LOG_NOTICE: return "notice";
394 	case RTE_LOG_INFO: return "info";
395 	case RTE_LOG_DEBUG: return "debug";
396 	default: return "unknown";
397 	}
398 }
399 
400 static int
401 log_type_compare(const void *a, const void *b)
402 {
403 	const struct rte_log_dynamic_type *type_a = a;
404 	const struct rte_log_dynamic_type *type_b = b;
405 
406 	if (type_a->name == NULL && type_b->name == NULL)
407 		return 0;
408 	if (type_a->name == NULL)
409 		return -1;
410 	if (type_b->name == NULL)
411 		return 1;
412 	return strcmp(type_a->name, type_b->name);
413 }
414 
415 /* Dump name of each logtype, one per line. */
416 void
417 rte_log_list_types(FILE *out, const char *prefix)
418 {
419 	struct rte_log_dynamic_type *sorted_types;
420 	const size_t type_size = sizeof(rte_logs.dynamic_types[0]);
421 	const size_t type_count = rte_logs.dynamic_types_len;
422 	const size_t total_size = type_size * type_count;
423 	size_t type;
424 
425 	sorted_types = malloc(total_size);
426 	if (sorted_types == NULL) {
427 		/* no sorting - unlikely */
428 		sorted_types = rte_logs.dynamic_types;
429 	} else {
430 		memcpy(sorted_types, rte_logs.dynamic_types, total_size);
431 		qsort(sorted_types, type_count, type_size, log_type_compare);
432 	}
433 
434 	for (type = 0; type < type_count; ++type) {
435 		if (sorted_types[type].name == NULL)
436 			continue;
437 		fprintf(out, "%s%s\n", prefix, sorted_types[type].name);
438 	}
439 
440 	if (sorted_types != rte_logs.dynamic_types)
441 		free(sorted_types);
442 }
443 
444 /* dump global level and registered log types */
445 void
446 rte_log_dump(FILE *f)
447 {
448 	size_t i;
449 
450 	fprintf(f, "global log level is %s\n",
451 		eal_log_level2str(rte_log_get_global_level()));
452 
453 	for (i = 0; i < rte_logs.dynamic_types_len; i++) {
454 		if (rte_logs.dynamic_types[i].name == NULL)
455 			continue;
456 		fprintf(f, "id %zu: %s, level is %s\n",
457 			i, rte_logs.dynamic_types[i].name,
458 			eal_log_level2str(rte_logs.dynamic_types[i].loglevel));
459 	}
460 }
461 
462 /*
463  * Generates a log message The message will be sent in the stream
464  * defined by the previous call to rte_openlog_stream().
465  */
466 int
467 rte_vlog(uint32_t level, uint32_t logtype, const char *format, va_list ap)
468 {
469 	FILE *f = rte_log_get_stream();
470 	int ret;
471 
472 	if (logtype >= rte_logs.dynamic_types_len)
473 		return -1;
474 	if (!rte_log_can_log(logtype, level))
475 		return 0;
476 
477 	/* save loglevel and logtype in a global per-lcore variable */
478 	RTE_PER_LCORE(log_cur_msg).loglevel = level;
479 	RTE_PER_LCORE(log_cur_msg).logtype = logtype;
480 
481 	ret = (*rte_logs.print_func)(f, format, ap);
482 	fflush(f);
483 	return ret;
484 }
485 
486 /*
487  * Generates a log message The message will be sent in the stream
488  * defined by the previous call to rte_openlog_stream().
489  * No need to check level here, done by rte_vlog().
490  */
491 int
492 rte_log(uint32_t level, uint32_t logtype, const char *format, ...)
493 {
494 	va_list ap;
495 	int ret;
496 
497 	va_start(ap, format);
498 	ret = rte_vlog(level, logtype, format, ap);
499 	va_end(ap);
500 	return ret;
501 }
502 
503 /*
504  * Called by rte_eal_init
505  */
506 void
507 eal_log_init(const char *id)
508 {
509 	/* If user has already set a log stream, then use it. */
510 	if (rte_logs.file == NULL) {
511 		FILE *logf = NULL;
512 
513 		/* if stderr is associated with systemd environment */
514 		if (log_journal_enabled())
515 			logf = log_journal_open(id);
516 		/* If --syslog option was passed */
517 		else if (log_syslog_enabled())
518 			logf = log_syslog_open(id);
519 
520 		/* if either syslog or journal is used, then no special handling */
521 		if (logf) {
522 			rte_openlog_stream(logf);
523 		} else {
524 			bool is_terminal = isatty(fileno(stderr));
525 			bool use_color = log_color_enabled(is_terminal);
526 
527 			if (log_timestamp_enabled()) {
528 				if (use_color)
529 					rte_logs.print_func = color_print_with_timestamp;
530 				else
531 					rte_logs.print_func = log_print_with_timestamp;
532 			} else {
533 				if (use_color)
534 					rte_logs.print_func = color_print;
535 				else
536 					rte_logs.print_func = vfprintf;
537 			}
538 		}
539 	}
540 
541 #if RTE_LOG_DP_LEVEL >= RTE_LOG_DEBUG
542 	RTE_LOG(NOTICE, EAL,
543 		"Debug dataplane logs available - lower performance\n");
544 #endif
545 }
546 
547 /*
548  * Called by eal_cleanup
549  */
550 void
551 rte_eal_log_cleanup(void)
552 {
553 	FILE *log_stream = rte_logs.file;
554 
555 	/* don't close stderr on the application */
556 	if (log_stream != NULL)
557 		fclose(log_stream);
558 
559 	rte_logs.file = NULL;
560 }
561