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