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