Branch data Line data Source code
1 : : /*
2 : : * Copyright (c) 2018 Nordic Semiconductor ASA
3 : : *
4 : : * SPDX-License-Identifier: Apache-2.0
5 : : */
6 : :
7 : : #undef _POSIX_C_SOURCE
8 : : #define _POSIX_C_SOURCE 200809L
9 : : #include <zephyr/logging/log_output.h>
10 : : #include <zephyr/logging/log_ctrl.h>
11 : : #include <zephyr/logging/log_output_custom.h>
12 : : #include <zephyr/logging/log.h>
13 : : #include <zephyr/sys/__assert.h>
14 : : #include <zephyr/sys/cbprintf.h>
15 : : #include <ctype.h>
16 : : #include <time.h>
17 : : #include <stdio.h>
18 : : #include <stdbool.h>
19 : :
20 : : #define LOG_COLOR_CODE_DEFAULT "\x1B[0m"
21 : : #define LOG_COLOR_CODE_RED "\x1B[1;31m"
22 : : #define LOG_COLOR_CODE_GREEN "\x1B[1;32m"
23 : : #define LOG_COLOR_CODE_YELLOW "\x1B[1;33m"
24 : : #define LOG_COLOR_CODE_BLUE "\x1B[1;34m"
25 : :
26 : : #define HEXDUMP_BYTES_IN_LINE 16
27 : :
28 : : #define DROPPED_COLOR_PREFIX \
29 : : COND_CODE_1(CONFIG_LOG_BACKEND_SHOW_COLOR, (LOG_COLOR_CODE_RED), ())
30 : :
31 : : #define DROPPED_COLOR_POSTFIX \
32 : : COND_CODE_1(CONFIG_LOG_BACKEND_SHOW_COLOR, (LOG_COLOR_CODE_DEFAULT), ())
33 : :
34 : : static const char *const severity[] = {
35 : : NULL,
36 : : "err",
37 : : "wrn",
38 : : "inf",
39 : : "dbg"
40 : : };
41 : :
42 : : static const char *const colors[] = {
43 : : NULL,
44 : : IS_ENABLED(CONFIG_LOG_BACKEND_SHOW_COLOR) ? LOG_COLOR_CODE_RED : NULL, /* err */
45 : : IS_ENABLED(CONFIG_LOG_BACKEND_SHOW_COLOR) ? LOG_COLOR_CODE_YELLOW : NULL, /* warn */
46 : : IS_ENABLED(CONFIG_LOG_INFO_COLOR_GREEN) ? LOG_COLOR_CODE_GREEN : NULL, /* info */
47 : : IS_ENABLED(CONFIG_LOG_DBG_COLOR_BLUE) ? LOG_COLOR_CODE_BLUE : NULL, /* dbg */
48 : : };
49 : :
50 : : static uint32_t freq;
51 : : static log_timestamp_t timestamp_div;
52 : :
53 : : /* The RFC 5424 allows very flexible mapping and suggest the value 0 being the
54 : : * highest severity and 7 to be the lowest (debugging level) severity.
55 : : *
56 : : * 0 Emergency System is unusable
57 : : * 1 Alert Action must be taken immediately
58 : : * 2 Critical Critical conditions
59 : : * 3 Error Error conditions
60 : : * 4 Warning Warning conditions
61 : : * 5 Notice Normal but significant condition
62 : : * 6 Informational Informational messages
63 : : * 7 Debug Debug-level messages
64 : : */
65 : : static int level_to_rfc5424_severity(uint32_t level)
66 : : {
67 : : uint8_t ret;
68 : :
69 : : switch (level) {
70 : : case LOG_LEVEL_NONE:
71 : : ret = 7U;
72 : : break;
73 : : case LOG_LEVEL_ERR:
74 : : ret = 3U;
75 : : break;
76 : : case LOG_LEVEL_WRN:
77 : : ret = 4U;
78 : : break;
79 : : case LOG_LEVEL_INF:
80 : : ret = 6U;
81 : : break;
82 : : case LOG_LEVEL_DBG:
83 : : ret = 7U;
84 : : break;
85 : : default:
86 : : ret = 7U;
87 : : break;
88 : : }
89 : :
90 : : return ret;
91 : : }
92 : :
93 : 8820 : static int out_func(int c, void *ctx)
94 : : {
95 : 8820 : const struct log_output *out_ctx = (const struct log_output *)ctx;
96 : 8820 : int idx;
97 : :
98 : 8820 : if (IS_ENABLED(CONFIG_LOG_MODE_IMMEDIATE)) {
99 : : /* Backend must be thread safe in synchronous operation. */
100 : : /* Need that step for big endian */
101 : 8820 : char x = (char)c;
102 : :
103 : 8820 : out_ctx->func((uint8_t *)&x, 1, out_ctx->control_block->ctx);
104 : 8820 : return 0;
105 : : }
106 : :
107 : : if (out_ctx->control_block->offset == out_ctx->size) {
108 : : log_output_flush(out_ctx);
109 : : }
110 : :
111 : : idx = atomic_inc(&out_ctx->control_block->offset);
112 : : out_ctx->buf[idx] = (uint8_t)c;
113 : :
114 : : __ASSERT_NO_MSG(out_ctx->control_block->offset <= out_ctx->size);
115 : :
116 : : return 0;
117 : : }
118 : :
119 : 8640 : static int cr_out_func(int c, void *ctx)
120 : : {
121 [ + + ]: 8640 : if (c == '\n') {
122 : 180 : out_func((int)'\r', ctx);
123 : : }
124 : 8640 : out_func(c, ctx);
125 : :
126 : 8640 : return 0;
127 : : }
128 : :
129 : 0 : static int print_formatted(const struct log_output *output,
130 : : const char *fmt, ...)
131 : : {
132 : 0 : va_list args;
133 : 0 : int length = 0;
134 : :
135 : 0 : va_start(args, fmt);
136 : 0 : length = cbvprintf(out_func, (void *)output, fmt, args);
137 : 0 : va_end(args);
138 : :
139 : 0 : return length;
140 : : }
141 : :
142 : 0 : static int timestamp_print(const struct log_output *output,
143 : : uint32_t flags, log_timestamp_t timestamp)
144 : : {
145 : 0 : int length;
146 : 0 : bool format =
147 : : (flags & LOG_OUTPUT_FLAG_FORMAT_TIMESTAMP) |
148 : : (flags & LOG_OUTPUT_FLAG_FORMAT_SYSLOG) |
149 : 0 : IS_ENABLED(CONFIG_LOG_OUTPUT_FORMAT_LINUX_TIMESTAMP) |
150 : : IS_ENABLED(CONFIG_LOG_OUTPUT_FORMAT_CUSTOM_TIMESTAMP);
151 : :
152 : :
153 [ # # ]: 0 : if (!format) {
154 : : #ifndef CONFIG_LOG_TIMESTAMP_64BIT
155 : 0 : length = print_formatted(output, "[%08lu] ", timestamp);
156 : : #else
157 : : length = print_formatted(output, "[%016llu] ", timestamp);
158 : : #endif
159 [ # # ]: 0 : } else if (freq != 0U) {
160 : : #ifndef CONFIG_LOG_TIMESTAMP_64BIT
161 : 0 : uint32_t total_seconds;
162 : : #else
163 : : uint64_t total_seconds;
164 : : #endif
165 : 0 : uint32_t remainder;
166 : 0 : uint32_t ms;
167 : 0 : uint32_t us;
168 : :
169 : 0 : timestamp /= timestamp_div;
170 : 0 : total_seconds = timestamp / freq;
171 : :
172 : 0 : remainder = timestamp % freq;
173 : 0 : ms = (remainder * 1000U) / freq;
174 : 0 : us = (1000 * (remainder * 1000U - (ms * freq))) / freq;
175 : :
176 : 0 : if (IS_ENABLED(CONFIG_LOG_BACKEND_NET) && flags & LOG_OUTPUT_FLAG_FORMAT_SYSLOG) {
177 : : #if defined(CONFIG_POSIX_C_LANG_SUPPORT_R)
178 : : struct tm tm_timestamp = {0};
179 : : time_t time_seconds = total_seconds;
180 : :
181 : : gmtime_r(&time_seconds, &tm_timestamp);
182 : : #if defined(CONFIG_REQUIRES_FULL_LIBC)
183 : : char time_str[sizeof("1970-01-01T00:00:00")];
184 : :
185 : : strftime(time_str, sizeof(time_str), "%FT%T", &tm_timestamp);
186 : :
187 : : length = print_formatted(output, "%s.%06uZ ",
188 : : time_str, ms * 1000U + us);
189 : : #else /* CONFIG_REQUIRES_FULL_LIBC */
190 : : length = print_formatted(output,
191 : : "%04u-%02u-%02uT%02u:%02u:%02u.%06uZ ",
192 : : tm_timestamp.tm_year + 1900, tm_timestamp.tm_mon + 1,
193 : : tm_timestamp.tm_mday, tm_timestamp.tm_hour,
194 : : tm_timestamp.tm_min, tm_timestamp.tm_sec,
195 : : ms * 1000U + us);
196 : : #endif /* CONFIG_REQUIRES_FULL_LIBC */
197 : : #endif /* CONFIG_POSIX_C_LANG_SUPPORT_R */
198 : 0 : } else if (IS_ENABLED(CONFIG_LOG_OUTPUT_FORMAT_CUSTOM_TIMESTAMP)) {
199 : : length = log_custom_timestamp_print(output, timestamp, print_formatted);
200 : : } else {
201 : 0 : if (IS_ENABLED(CONFIG_LOG_OUTPUT_FORMAT_LINUX_TIMESTAMP)) {
202 : : length = print_formatted(output,
203 : : #if defined(CONFIG_LOG_TIMESTAMP_64BIT)
204 : : "[%5llu.%06d] ",
205 : : #else
206 : : "[%5lu.%06d] ",
207 : : #endif
208 : : total_seconds, ms * 1000U + us);
209 : : #if defined(CONFIG_POSIX_C_LANG_SUPPORT_R)
210 : 0 : } else if (IS_ENABLED(CONFIG_LOG_OUTPUT_FORMAT_DATE_TIMESTAMP)) {
211 : : struct tm tm_timestamp = {0};
212 : : time_t time_seconds = total_seconds;
213 : :
214 : : gmtime_r(&time_seconds, &tm_timestamp);
215 : : #if defined(CONFIG_REQUIRES_FULL_LIBC)
216 : : char time_str[sizeof("1970-01-01 00:00:00")];
217 : :
218 : : strftime(time_str, sizeof(time_str), "%F %T", &tm_timestamp);
219 : :
220 : : length = print_formatted(output, "[%s.%03u,%03u] ", time_str, ms,
221 : : us);
222 : : #else /* CONFIG_REQUIRES_FULL_LIBC */
223 : : length = print_formatted(
224 : : output, "[%04u-%02u-%02u %02u:%02u:%02u.%03u,%03u] ",
225 : : tm_timestamp.tm_year + 1900, tm_timestamp.tm_mon + 1,
226 : : tm_timestamp.tm_mday, tm_timestamp.tm_hour,
227 : : tm_timestamp.tm_min, tm_timestamp.tm_sec,
228 : : ms, us);
229 : : #endif /* CONFIG_REQUIRES_FULL_LIBC */
230 : 0 : } else if (IS_ENABLED(CONFIG_LOG_OUTPUT_FORMAT_ISO8601_TIMESTAMP)) {
231 : : struct tm tm_timestamp = {0};
232 : : time_t time_seconds = total_seconds;
233 : :
234 : : gmtime_r(&time_seconds, &tm_timestamp);
235 : : #if defined(CONFIG_REQUIRES_FULL_LIBC)
236 : : char time_str[sizeof("1970-01-01T00:00:00")];
237 : :
238 : : strftime(time_str, sizeof(time_str), "%FT%T", &tm_timestamp);
239 : :
240 : : length = print_formatted(output, "[%s,%06uZ] ", time_str,
241 : : ms * 1000U + us);
242 : : #else /* CONFIG_REQUIRES_FULL_LIBC */
243 : : length = print_formatted(output,
244 : : "[%04u-%02u-%02uT%02u:%02u:%02u,%06uZ] ",
245 : : tm_timestamp.tm_year + 1900,
246 : : tm_timestamp.tm_mon + 1,
247 : : tm_timestamp.tm_mday, tm_timestamp.tm_hour,
248 : : tm_timestamp.tm_min, tm_timestamp.tm_sec,
249 : : ms * 1000U + us);
250 : : #endif /* CONFIG_REQUIRES_FULL_LIBC */
251 : : #endif /* CONFIG_POSIX_C_LANG_SUPPORT_R */
252 : : } else {
253 : 0 : uint32_t seconds;
254 : 0 : uint32_t hours;
255 : 0 : uint32_t mins;
256 : :
257 : 0 : seconds = total_seconds;
258 : 0 : hours = seconds / 3600U;
259 : 0 : seconds -= hours * 3600U;
260 : 0 : mins = seconds / 60U;
261 : 0 : seconds -= mins * 60U;
262 : 0 : length = print_formatted(output,
263 : : "[%02u:%02u:%02u.%03u,%03u] ",
264 : : hours, mins, seconds, ms, us);
265 : : }
266 : : }
267 : : } else {
268 : : length = 0;
269 : : }
270 : :
271 : 0 : return length;
272 : : }
273 : :
274 : 0 : static void color_print(const struct log_output *output,
275 : : bool color, bool start, uint32_t level)
276 : : {
277 [ # # ]: 0 : if (color) {
278 [ # # ]: 0 : const char *log_color = start && (colors[level] != NULL) ?
279 [ # # ]: 0 : colors[level] : LOG_COLOR_CODE_DEFAULT;
280 : 0 : print_formatted(output, "%s", log_color);
281 : : }
282 : 0 : }
283 : :
284 : 0 : static void color_prefix(const struct log_output *output,
285 : : bool color, uint32_t level)
286 : : {
287 : 0 : color_print(output, color, true, level);
288 : 0 : }
289 : :
290 : 0 : static void color_postfix(const struct log_output *output,
291 : : bool color, uint32_t level)
292 : : {
293 : 0 : color_print(output, color, false, level);
294 : 0 : }
295 : :
296 : :
297 : 0 : static int ids_print(const struct log_output *output,
298 : : bool level_on,
299 : : bool func_on,
300 : : bool thread_on,
301 : : const char *domain,
302 : : const char *source,
303 : : k_tid_t tid,
304 : : uint32_t level)
305 : : {
306 : 0 : int total = 0;
307 : :
308 [ # # ]: 0 : if (level_on) {
309 : 0 : total += print_formatted(output, "<%s> ", severity[level]);
310 : : }
311 : :
312 : 0 : if (IS_ENABLED(CONFIG_LOG_THREAD_ID_PREFIX) && thread_on) {
313 : : if (tid == NULL) {
314 : : total += print_formatted(output, "[irq] ");
315 : : } else if (IS_ENABLED(CONFIG_THREAD_NAME)) {
316 : : total += print_formatted(output,
317 : : "[%3d %s] ",
318 : : k_thread_priority_get(tid),
319 : : k_thread_name_get(tid));
320 : : } else {
321 : : total += print_formatted(output,
322 : : "[%3d %p] ",
323 : : k_thread_priority_get(tid),
324 : : tid);
325 : : }
326 : : }
327 : :
328 [ # # ]: 0 : if (domain) {
329 : 0 : total += print_formatted(output, "%s/", domain);
330 : : }
331 : :
332 [ # # ]: 0 : if (source) {
333 : 0 : total += print_formatted(output,
334 [ # # ]: 0 : (func_on &&
335 : : ((1 << level) & LOG_FUNCTION_PREFIX_MASK)) ?
336 : : "%s." : "%s: ",
337 : : source);
338 : : }
339 : :
340 : 0 : return total;
341 : : }
342 : :
343 : 0 : static void newline_print(const struct log_output *ctx, uint32_t flags)
344 : : {
345 : 0 : if (IS_ENABLED(CONFIG_LOG_BACKEND_NET) &&
346 : : flags & LOG_OUTPUT_FLAG_FORMAT_SYSLOG) {
347 : : return;
348 : : }
349 : :
350 [ # # ]: 0 : if ((flags & LOG_OUTPUT_FLAG_CRLF_NONE) != 0U) {
351 : : return;
352 : : }
353 : :
354 [ # # ]: 0 : if ((flags & LOG_OUTPUT_FLAG_CRLF_LFONLY) != 0U) {
355 : 0 : print_formatted(ctx, "\n");
356 : : } else {
357 : 0 : print_formatted(ctx, "\r\n");
358 : : }
359 : : }
360 : :
361 : 0 : static void hexdump_line_print(const struct log_output *output,
362 : : const uint8_t *data, uint32_t length,
363 : : int prefix_offset, uint32_t flags)
364 : : {
365 : 0 : newline_print(output, flags);
366 : :
367 [ # # ]: 0 : for (int i = 0; i < prefix_offset; i++) {
368 : 0 : print_formatted(output, " ");
369 : : }
370 : :
371 [ # # ]: 0 : for (int i = 0; i < HEXDUMP_BYTES_IN_LINE; i++) {
372 [ # # # # ]: 0 : if (i > 0 && !(i % 8)) {
373 : 0 : print_formatted(output, " ");
374 : : }
375 : :
376 [ # # ]: 0 : if (i < length) {
377 : 0 : print_formatted(output, "%02x ", data[i]);
378 : : } else {
379 : 0 : print_formatted(output, " ");
380 : : }
381 : : }
382 : :
383 : 0 : print_formatted(output, "|");
384 : :
385 [ # # ]: 0 : for (int i = 0; i < HEXDUMP_BYTES_IN_LINE; i++) {
386 [ # # # # ]: 0 : if (i > 0 && !(i % 8)) {
387 : 0 : print_formatted(output, " ");
388 : : }
389 : :
390 [ # # ]: 0 : if (i < length) {
391 : 0 : unsigned char c = (unsigned char)data[i];
392 : :
393 : 0 : print_formatted(output, "%c",
394 [ # # ]: 0 : isprint((int)c) != 0 ? c : '.');
395 : : } else {
396 : 0 : print_formatted(output, " ");
397 : : }
398 : : }
399 : 0 : }
400 : :
401 : 0 : static void log_msg_hexdump(const struct log_output *output,
402 : : uint8_t *data, uint32_t len,
403 : : int prefix_offset, uint32_t flags)
404 : : {
405 : 0 : size_t length;
406 : :
407 : 0 : do {
408 : 0 : length = MIN(len, HEXDUMP_BYTES_IN_LINE);
409 : :
410 : 0 : hexdump_line_print(output, data, length,
411 : : prefix_offset, flags);
412 : 0 : data += length;
413 : 0 : len -= length;
414 [ # # ]: 0 : } while (len);
415 : 0 : }
416 : :
417 : : #if defined(CONFIG_LOG_BACKEND_NET_RFC5424_SDATA_SEQID)
418 : : static int32_t get_sequence_id(void)
419 : : {
420 : : static int32_t id;
421 : :
422 : : if (++id < 0) {
423 : : id = 1;
424 : : }
425 : :
426 : : return id;
427 : : }
428 : : #endif
429 : :
430 : : #if defined(CONFIG_LOG_BACKEND_NET_RFC5424_SDATA_TZKNOWN)
431 : : static bool is_tzknown(void)
432 : : {
433 : : /* TODO: use proper implementation */
434 : : return false;
435 : : }
436 : : #endif
437 : :
438 : : #if defined(CONFIG_LOG_BACKEND_NET_RFC5424_SDATA_ISSYNCED)
439 : : static bool is_synced(void)
440 : : {
441 : : /* TODO: use proper implementation */
442 : : return IS_ENABLED(CONFIG_SNTP);
443 : : }
444 : : #endif
445 : :
446 : : static int syslog_print(const struct log_output *output,
447 : : bool level_on,
448 : : bool func_on,
449 : : bool *thread_on,
450 : : const char *domain,
451 : : const char *source,
452 : : k_tid_t tid,
453 : : uint32_t level,
454 : : uint32_t length)
455 : : {
456 : : uint32_t len = length;
457 : :
458 : : /* The syslog output format is:
459 : : * HOSTNAME SP APP-NAME SP PROCID SP MSGID SP STRUCTURED-DATA
460 : : */
461 : :
462 : : /* First HOSTNAME */
463 : : len += print_formatted(output, "%s ",
464 : : output->control_block->hostname ?
465 : : output->control_block->hostname :
466 : : "zephyr");
467 : :
468 : : /* Then APP-NAME. We use the thread name here. It should not
469 : : * contain any space characters.
470 : : */
471 : : if (*thread_on) {
472 : : if (IS_ENABLED(CONFIG_THREAD_NAME)) {
473 : : if (strstr(k_thread_name_get(tid), " ") != NULL) {
474 : : goto do_not_print_name;
475 : : }
476 : :
477 : : len += print_formatted(output, "%s ",
478 : : tid == NULL ?
479 : : "irq" :
480 : : k_thread_name_get(tid));
481 : : } else {
482 : : do_not_print_name:
483 : : len += print_formatted(output, "%p ", tid);
484 : : }
485 : :
486 : : /* Do not print thread id in the message as it was already
487 : : * printed above.
488 : : */
489 : : *thread_on = false;
490 : : } else {
491 : : /* No APP-NAME */
492 : : len += print_formatted(output, "- ");
493 : : }
494 : :
495 : : if (!IS_ENABLED(CONFIG_LOG_BACKEND_NET_RFC5424_STRUCTURED_DATA)) {
496 : : /* No PROCID, MSGID or STRUCTURED-DATA */
497 : : len += print_formatted(output, "- - - ");
498 : :
499 : : return len;
500 : : }
501 : :
502 : :
503 : : #if defined(CONFIG_LOG_BACKEND_NET_RFC5424_SDATA_SOFTWARE) || \
504 : : defined(CONFIG_LOG_BACKEND_NET_RFC5424_SDATA_SOFTWARE_VERSION)
505 : : #define STRUCTURED_DATA_ORIGIN_START "[origin"
506 : : #define STRUCTURED_DATA_ORIGIN_SW " software=\"%s\""
507 : : #define STRUCTURED_DATA_ORIGIN_SW_VERSION " swVersion=\"%u\""
508 : : #define STRUCTURED_DATA_ORIGIN_END "]"
509 : : #define STRUCTURED_DATA_ORIGIN \
510 : : STRUCTURED_DATA_ORIGIN_START \
511 : : COND_CODE_1(CONFIG_LOG_BACKEND_NET_RFC5424_SDATA_SOFTWARE, \
512 : : (STRUCTURED_DATA_ORIGIN_SW), ("%s")) \
513 : : COND_CODE_1(CONFIG_LOG_BACKEND_NET_RFC5424_SDATA_SOFTWARE_VERSION,\
514 : : (STRUCTURED_DATA_ORIGIN_SW_VERSION), ("%s")) \
515 : : STRUCTURED_DATA_ORIGIN_END
516 : : #else
517 : : #define STRUCTURED_DATA_ORIGIN "%s%s"
518 : : #endif
519 : :
520 : : #if defined(CONFIG_LOG_BACKEND_NET_RFC5424_SDATA_SEQID) || \
521 : : defined(CONFIG_LOG_BACKEND_NET_RFC5424_SDATA_UPTIME)
522 : : #define STRUCTURED_DATA_META_START "[meta"
523 : : #define STRUCTURED_DATA_META_SEQID " sequenceId=\"%d\""
524 : : #define STRUCTURED_DATA_META_UPTIME " sysUpTime=\"%d\""
525 : : #define STRUCTURED_DATA_META_END "]"
526 : : #define STRUCTURED_DATA_META \
527 : : STRUCTURED_DATA_META_START \
528 : : COND_CODE_1(CONFIG_LOG_BACKEND_NET_RFC5424_SDATA_SEQID, \
529 : : (STRUCTURED_DATA_META_SEQID), ("%s")) \
530 : : COND_CODE_1(CONFIG_LOG_BACKEND_NET_RFC5424_SDATA_UPTIME, \
531 : : (STRUCTURED_DATA_META_UPTIME), ("%s")) \
532 : : STRUCTURED_DATA_META_END
533 : : #else
534 : : #define STRUCTURED_DATA_META "%s%s"
535 : : #endif
536 : :
537 : : #if defined(CONFIG_LOG_BACKEND_NET_RFC5424_SDATA_TZKNOWN) || \
538 : : defined(CONFIG_LOG_BACKEND_NET_RFC5424_SDATA_ISSYNCED)
539 : : #define STRUCTURED_DATA_TIMEQUALITY_START "[timeQuality"
540 : : #define STRUCTURED_DATA_TIMEQUALITY_TZKNOWN " tzKnown=\"%d\""
541 : : #define STRUCTURED_DATA_TIMEQUALITY_ISSYNCED " isSynced=\"%d\""
542 : : #define STRUCTURED_DATA_TIMEQUALITY_END "]"
543 : : #define STRUCTURED_DATA_TIMEQUALITY \
544 : : STRUCTURED_DATA_TIMEQUALITY_START \
545 : : COND_CODE_1(CONFIG_LOG_BACKEND_NET_RFC5424_SDATA_TZKNOWN, \
546 : : (STRUCTURED_DATA_TIMEQUALITY_TZKNOWN), ("%s")) \
547 : : COND_CODE_1(CONFIG_LOG_BACKEND_NET_RFC5424_SDATA_ISSYNCED, \
548 : : (STRUCTURED_DATA_TIMEQUALITY_ISSYNCED), ("%s")) \
549 : : STRUCTURED_DATA_TIMEQUALITY_END
550 : : #else
551 : : #define STRUCTURED_DATA_TIMEQUALITY "%s%s"
552 : : #endif
553 : :
554 : : /* No PROCID or MSGID, but there is structured data.
555 : : */
556 : : len += print_formatted(output,
557 : : "- - "
558 : : STRUCTURED_DATA_META
559 : : STRUCTURED_DATA_ORIGIN
560 : : STRUCTURED_DATA_TIMEQUALITY,
561 : : COND_CODE_1(CONFIG_LOG_BACKEND_NET_RFC5424_SDATA_SEQID,
562 : : (get_sequence_id()), ("")),
563 : : COND_CODE_1(CONFIG_LOG_BACKEND_NET_RFC5424_SDATA_UPTIME,
564 : : /* in hundredths of a sec */
565 : : (k_uptime_get_32() / 10), ("")),
566 : : COND_CODE_1(CONFIG_LOG_BACKEND_NET_RFC5424_SDATA_SOFTWARE,
567 : : (CONFIG_LOG_BACKEND_NET_RFC5424_SDATA_SOFTWARE_VALUE),
568 : : ("")),
569 : : COND_CODE_1(CONFIG_LOG_BACKEND_NET_RFC5424_SDATA_SOFTWARE_VERSION,
570 : : (sys_kernel_version_get()), ("")),
571 : : COND_CODE_1(CONFIG_LOG_BACKEND_NET_RFC5424_SDATA_TZKNOWN,
572 : : (is_tzknown()), ("")),
573 : : COND_CODE_1(CONFIG_LOG_BACKEND_NET_RFC5424_SDATA_ISSYNCED,
574 : : (is_synced()), (""))
575 : : );
576 : :
577 : : return len;
578 : : }
579 : :
580 : 0 : static uint32_t prefix_print(const struct log_output *output,
581 : : uint32_t flags,
582 : : bool func_on,
583 : : log_timestamp_t timestamp,
584 : : const char *domain,
585 : : const char *source,
586 : : k_tid_t tid,
587 : : uint8_t level)
588 : : {
589 [ # # ]: 0 : __ASSERT_NO_MSG(level <= LOG_LEVEL_DBG);
590 : 0 : uint32_t length = 0U;
591 : :
592 : 0 : bool stamp = flags & LOG_OUTPUT_FLAG_TIMESTAMP;
593 : 0 : bool colors_on = flags & LOG_OUTPUT_FLAG_COLORS;
594 : 0 : bool level_on = flags & LOG_OUTPUT_FLAG_LEVEL;
595 : 0 : bool thread_on = IS_ENABLED(CONFIG_LOG_THREAD_ID_PREFIX) &&
596 : : (flags & LOG_OUTPUT_FLAG_THREAD);
597 : 0 : bool source_off = flags & LOG_OUTPUT_FLAG_SKIP_SOURCE;
598 : 0 : const char *tag = IS_ENABLED(CONFIG_LOG) ? z_log_get_tag() : NULL;
599 : :
600 : 0 : if (IS_ENABLED(CONFIG_LOG_BACKEND_NET) &&
601 : : flags & LOG_OUTPUT_FLAG_FORMAT_SYSLOG) {
602 : : /* TODO: As there is no way to figure out the
603 : : * facility at this point, use a pre-defined value.
604 : : * Change this to use the real facility of the
605 : : * logging call when that info is available.
606 : : */
607 : : static const int facility = 16; /* local0 */
608 : :
609 : : length += print_formatted(
610 : : output,
611 : : /* <PRI>VERSION */
612 : : "<%d>1 ",
613 : : facility * 8 +
614 : : level_to_rfc5424_severity(level));
615 : : }
616 : :
617 [ # # ]: 0 : if (tag) {
618 : 0 : length += print_formatted(output, "%s ", tag);
619 : : }
620 : :
621 [ # # ]: 0 : if (stamp) {
622 : 0 : length += timestamp_print(output, flags, timestamp);
623 : : }
624 : :
625 : 0 : if (IS_ENABLED(CONFIG_LOG_BACKEND_NET) &&
626 : : flags & LOG_OUTPUT_FLAG_FORMAT_SYSLOG) {
627 : : length += syslog_print(output, level_on, func_on, &thread_on, domain,
628 : : source_off ? NULL : source, tid, level, length);
629 : : } else {
630 : 0 : color_prefix(output, colors_on, level);
631 : : }
632 : :
633 [ # # ]: 0 : length += ids_print(output, level_on, func_on, thread_on, domain,
634 : : source_off ? NULL : source, tid, level);
635 : :
636 : 0 : return length;
637 : : }
638 : :
639 : 0 : static void postfix_print(const struct log_output *output,
640 : : uint32_t flags, uint8_t level)
641 : : {
642 : 0 : color_postfix(output, (flags & LOG_OUTPUT_FLAG_COLORS),
643 : : level);
644 : 0 : newline_print(output, flags);
645 : 0 : }
646 : :
647 : 177 : void log_output_process(const struct log_output *output,
648 : : log_timestamp_t timestamp,
649 : : const char *domain,
650 : : const char *source,
651 : : k_tid_t tid,
652 : : uint8_t level,
653 : : const uint8_t *package,
654 : : const uint8_t *data,
655 : : size_t data_len,
656 : : uint32_t flags)
657 : : {
658 : 177 : bool raw_string = (level == LOG_LEVEL_INTERNAL_RAW_STRING);
659 : 177 : uint32_t prefix_offset;
660 : 177 : cbprintf_cb cb;
661 : :
662 [ - + ]: 177 : if (!raw_string) {
663 : 0 : prefix_offset = prefix_print(output, flags, 0, timestamp,
664 : : domain, source, tid, level);
665 : 0 : cb = out_func;
666 : : } else {
667 : 177 : prefix_offset = 0;
668 : : /* source set to 1 indicates raw string and contrary to printk
669 : : * case it should not append anything to the output (printk is
670 : : * appending <CR> to the new line character).
671 : : */
672 [ + - ]: 177 : cb = ((uintptr_t)source == 1) ? out_func : cr_out_func;
673 : : }
674 : :
675 [ + - ]: 177 : if (package) {
676 : 177 : int err = cbpprintf(cb, (void *)output, (void *)package);
677 : :
678 : 177 : (void)err;
679 [ - + ]: 177 : __ASSERT_NO_MSG(err >= 0);
680 : : }
681 : :
682 [ - + ]: 177 : if (data_len) {
683 : 0 : log_msg_hexdump(output, (uint8_t *)data, data_len, prefix_offset, flags);
684 : : }
685 : :
686 [ - + ]: 177 : if (!raw_string) {
687 : 0 : postfix_print(output, flags, level);
688 : : }
689 : :
690 : 177 : log_output_flush(output);
691 : 177 : }
692 : :
693 : 177 : void log_output_msg_process(const struct log_output *output,
694 : : struct log_msg *msg, uint32_t flags)
695 : : {
696 : 177 : log_timestamp_t timestamp = log_msg_get_timestamp(msg);
697 : 177 : uint8_t level = log_msg_get_level(msg);
698 : 177 : uint8_t domain_id = log_msg_get_domain(msg);
699 : 177 : int16_t source_id = log_msg_get_source_id(msg);
700 : :
701 : 177 : const char *dname = IS_ENABLED(CONFIG_LOG_DOMAIN_NAME_PREFIX) ?
702 : : log_domain_name_get(domain_id) : NULL;
703 [ - + ]: 177 : const char *sname = source_id >= 0 ? log_source_name_get(domain_id, source_id) : NULL;
704 : 177 : size_t plen, dlen;
705 : 177 : uint8_t *package = log_msg_get_package(msg, &plen);
706 : 177 : uint8_t *data = log_msg_get_data(msg, &dlen);
707 : :
708 : 177 : log_output_process(output, timestamp, dname, sname, (k_tid_t)log_msg_get_tid(msg), level,
709 [ - + ]: 177 : plen > 0 ? package : NULL, data, dlen, flags);
710 : 177 : }
711 : :
712 : 0 : void log_output_dropped_process(const struct log_output *output, uint32_t cnt)
713 : : {
714 : 0 : char buf[5];
715 : 0 : int len;
716 : 0 : static const char prefix[] = DROPPED_COLOR_PREFIX "--- ";
717 : 0 : static const char postfix[] =
718 : : " messages dropped ---\r\n" DROPPED_COLOR_POSTFIX;
719 : 0 : log_output_func_t outf = output->func;
720 : :
721 : 0 : cnt = MIN(cnt, 9999);
722 : 0 : len = snprintk(buf, sizeof(buf), "%d", cnt);
723 : :
724 : 0 : log_output_write(outf, (uint8_t *)prefix, sizeof(prefix) - 1, output->control_block->ctx);
725 : 0 : log_output_write(outf, buf, len, output->control_block->ctx);
726 : 0 : log_output_write(outf, (uint8_t *)postfix, sizeof(postfix) - 1, output->control_block->ctx);
727 : 0 : }
728 : :
729 : 1 : void log_output_timestamp_freq_set(uint32_t frequency)
730 : : {
731 : 1 : timestamp_div = 1U;
732 : : /* There is no point to have frequency higher than 1MHz (ns are not
733 : : * printed) and too high frequency leads to overflows in calculations.
734 : : */
735 [ - + ]: 1 : while (frequency > 1000000) {
736 : 0 : frequency /= 2U;
737 : 0 : timestamp_div *= 2U;
738 : : }
739 : :
740 : 1 : freq = frequency;
741 : 1 : }
742 : :
743 : 0 : uint64_t log_output_timestamp_to_us(log_timestamp_t timestamp)
744 : : {
745 : 0 : timestamp /= timestamp_div;
746 : :
747 : 0 : return ((uint64_t) timestamp * 1000000U) / freq;
748 : : }
|
