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