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 */
level_to_rfc5424_severity(uint32_t level)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
out_func(int c,void * ctx)93 static int out_func(int c, void *ctx)
94 {
95 const struct log_output *out_ctx = (const struct log_output *)ctx;
96 int idx;
97
98 if (IS_ENABLED(CONFIG_LOG_MODE_IMMEDIATE)) {
99 /* Backend must be thread safe in synchronous operation. */
100 /* Need that step for big endian */
101 char x = (char)c;
102
103 out_ctx->func((uint8_t *)&x, 1, out_ctx->control_block->ctx);
104 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
cr_out_func(int c,void * ctx)119 static int cr_out_func(int c, void *ctx)
120 {
121 if (c == '\n') {
122 out_func((int)'\r', ctx);
123 }
124 out_func(c, ctx);
125
126 return 0;
127 }
128
print_formatted(const struct log_output * output,const char * fmt,...)129 static int print_formatted(const struct log_output *output,
130 const char *fmt, ...)
131 {
132 va_list args;
133 int length = 0;
134
135 va_start(args, fmt);
136 length = cbvprintf(out_func, (void *)output, fmt, args);
137 va_end(args);
138
139 return length;
140 }
141
timestamp_print(const struct log_output * output,uint32_t flags,log_timestamp_t timestamp)142 static int timestamp_print(const struct log_output *output,
143 uint32_t flags, log_timestamp_t timestamp)
144 {
145 int length;
146 bool format =
147 (flags & LOG_OUTPUT_FLAG_FORMAT_TIMESTAMP) |
148 (flags & LOG_OUTPUT_FLAG_FORMAT_SYSLOG) |
149 IS_ENABLED(CONFIG_LOG_OUTPUT_FORMAT_LINUX_TIMESTAMP) |
150 IS_ENABLED(CONFIG_LOG_OUTPUT_FORMAT_CUSTOM_TIMESTAMP);
151
152
153 if (!format) {
154 #ifndef CONFIG_LOG_TIMESTAMP_64BIT
155 length = print_formatted(output, "[%08lu] ", timestamp);
156 #else
157 length = print_formatted(output, "[%016llu] ", timestamp);
158 #endif
159 } else if (freq != 0U) {
160 #ifndef CONFIG_LOG_TIMESTAMP_64BIT
161 uint32_t total_seconds;
162 #else
163 uint64_t total_seconds;
164 #endif
165 uint32_t remainder;
166 uint32_t ms;
167 uint32_t us;
168
169 timestamp /= timestamp_div;
170 total_seconds = timestamp / freq;
171
172 remainder = timestamp % freq;
173 ms = (remainder * 1000U) / freq;
174 us = (1000 * (remainder * 1000U - (ms * freq))) / freq;
175
176 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 } else if (IS_ENABLED(CONFIG_LOG_OUTPUT_FORMAT_CUSTOM_TIMESTAMP)) {
199 length = log_custom_timestamp_print(output, timestamp, print_formatted);
200 } else {
201 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 } 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 } 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 uint32_t seconds;
254 uint32_t hours;
255 uint32_t mins;
256
257 seconds = total_seconds;
258 hours = seconds / 3600U;
259 seconds -= hours * 3600U;
260 mins = seconds / 60U;
261 seconds -= mins * 60U;
262 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 return length;
272 }
273
color_print(const struct log_output * output,bool color,bool start,uint32_t level)274 static void color_print(const struct log_output *output,
275 bool color, bool start, uint32_t level)
276 {
277 if (color) {
278 const char *log_color = start && (colors[level] != NULL) ?
279 colors[level] : LOG_COLOR_CODE_DEFAULT;
280 print_formatted(output, "%s", log_color);
281 }
282 }
283
color_prefix(const struct log_output * output,bool color,uint32_t level)284 static void color_prefix(const struct log_output *output,
285 bool color, uint32_t level)
286 {
287 color_print(output, color, true, level);
288 }
289
color_postfix(const struct log_output * output,bool color,uint32_t level)290 static void color_postfix(const struct log_output *output,
291 bool color, uint32_t level)
292 {
293 color_print(output, color, false, level);
294 }
295
296
ids_print(const struct log_output * output,bool level_on,bool func_on,bool thread_on,const char * domain,const char * source,k_tid_t tid,uint32_t level)297 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 int total = 0;
307
308 if (level_on) {
309 total += print_formatted(output, "<%s> ", severity[level]);
310 }
311
312 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 if (domain) {
329 total += print_formatted(output, "%s/", domain);
330 }
331
332 if (source) {
333 total += print_formatted(output,
334 (func_on &&
335 ((1 << level) & LOG_FUNCTION_PREFIX_MASK)) ?
336 "%s." : "%s: ",
337 source);
338 }
339
340 return total;
341 }
342
newline_print(const struct log_output * ctx,uint32_t flags)343 static void newline_print(const struct log_output *ctx, uint32_t flags)
344 {
345 if (IS_ENABLED(CONFIG_LOG_BACKEND_NET) &&
346 flags & LOG_OUTPUT_FLAG_FORMAT_SYSLOG) {
347 return;
348 }
349
350 if ((flags & LOG_OUTPUT_FLAG_CRLF_NONE) != 0U) {
351 return;
352 }
353
354 if ((flags & LOG_OUTPUT_FLAG_CRLF_LFONLY) != 0U) {
355 print_formatted(ctx, "\n");
356 } else {
357 print_formatted(ctx, "\r\n");
358 }
359 }
360
hexdump_line_print(const struct log_output * output,const uint8_t * data,uint32_t length,int prefix_offset,uint32_t flags)361 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 newline_print(output, flags);
366
367 for (int i = 0; i < prefix_offset; i++) {
368 print_formatted(output, " ");
369 }
370
371 for (int i = 0; i < HEXDUMP_BYTES_IN_LINE; i++) {
372 if (i > 0 && !(i % 8)) {
373 print_formatted(output, " ");
374 }
375
376 if (i < length) {
377 print_formatted(output, "%02x ", data[i]);
378 } else {
379 print_formatted(output, " ");
380 }
381 }
382
383 print_formatted(output, "|");
384
385 for (int i = 0; i < HEXDUMP_BYTES_IN_LINE; i++) {
386 if (i > 0 && !(i % 8)) {
387 print_formatted(output, " ");
388 }
389
390 if (i < length) {
391 unsigned char c = (unsigned char)data[i];
392
393 print_formatted(output, "%c",
394 isprint((int)c) != 0 ? c : '.');
395 } else {
396 print_formatted(output, " ");
397 }
398 }
399 }
400
log_msg_hexdump(const struct log_output * output,uint8_t * data,uint32_t len,int prefix_offset,uint32_t flags)401 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 size_t length;
406
407 do {
408 length = MIN(len, HEXDUMP_BYTES_IN_LINE);
409
410 hexdump_line_print(output, data, length,
411 prefix_offset, flags);
412 data += length;
413 len -= length;
414 } while (len);
415 }
416
417 #if defined(CONFIG_LOG_BACKEND_NET_RFC5424_SDATA_SEQID)
get_sequence_id(void)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)
is_tzknown(void)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)
is_synced(void)439 static bool is_synced(void)
440 {
441 /* TODO: use proper implementation */
442 return IS_ENABLED(CONFIG_SNTP);
443 }
444 #endif
445
syslog_print(const struct log_output * output,bool level_on,bool func_on,bool * thread_on,const char * domain,const char * source,k_tid_t tid,uint32_t level,uint32_t length)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
prefix_print(const struct log_output * output,uint32_t flags,bool func_on,log_timestamp_t timestamp,const char * domain,const char * source,k_tid_t tid,uint8_t level)580 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 __ASSERT_NO_MSG(level <= LOG_LEVEL_DBG);
590 uint32_t length = 0U;
591
592 bool stamp = flags & LOG_OUTPUT_FLAG_TIMESTAMP;
593 bool colors_on = flags & LOG_OUTPUT_FLAG_COLORS;
594 bool level_on = flags & LOG_OUTPUT_FLAG_LEVEL;
595 bool thread_on = IS_ENABLED(CONFIG_LOG_THREAD_ID_PREFIX) &&
596 (flags & LOG_OUTPUT_FLAG_THREAD);
597 bool source_off = flags & LOG_OUTPUT_FLAG_SKIP_SOURCE;
598 const char *tag = IS_ENABLED(CONFIG_LOG) ? z_log_get_tag() : NULL;
599
600 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 if (tag) {
618 length += print_formatted(output, "%s ", tag);
619 }
620
621 if (stamp) {
622 length += timestamp_print(output, flags, timestamp);
623 }
624
625 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 color_prefix(output, colors_on, level);
631 }
632
633 length += ids_print(output, level_on, func_on, thread_on, domain,
634 source_off ? NULL : source, tid, level);
635
636 return length;
637 }
638
postfix_print(const struct log_output * output,uint32_t flags,uint8_t level)639 static void postfix_print(const struct log_output *output,
640 uint32_t flags, uint8_t level)
641 {
642 color_postfix(output, (flags & LOG_OUTPUT_FLAG_COLORS),
643 level);
644 newline_print(output, flags);
645 }
646
log_output_process(const struct log_output * output,log_timestamp_t timestamp,const char * domain,const char * source,k_tid_t tid,uint8_t level,const uint8_t * package,const uint8_t * data,size_t data_len,uint32_t flags)647 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 bool raw_string = (level == LOG_LEVEL_INTERNAL_RAW_STRING);
659 uint32_t prefix_offset;
660 cbprintf_cb cb;
661
662 if (!raw_string) {
663 prefix_offset = prefix_print(output, flags, 0, timestamp,
664 domain, source, tid, level);
665 cb = out_func;
666 } else {
667 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 cb = ((uintptr_t)source == 1) ? out_func : cr_out_func;
673 }
674
675 if (package) {
676 int err = cbpprintf(cb, (void *)output, (void *)package);
677
678 (void)err;
679 __ASSERT_NO_MSG(err >= 0);
680 }
681
682 if (data_len) {
683 log_msg_hexdump(output, (uint8_t *)data, data_len, prefix_offset, flags);
684 }
685
686 if (!raw_string) {
687 postfix_print(output, flags, level);
688 }
689
690 log_output_flush(output);
691 }
692
log_output_msg_process(const struct log_output * output,struct log_msg * msg,uint32_t flags)693 void log_output_msg_process(const struct log_output *output,
694 struct log_msg *msg, uint32_t flags)
695 {
696 log_timestamp_t timestamp = log_msg_get_timestamp(msg);
697 uint8_t level = log_msg_get_level(msg);
698 uint8_t domain_id = log_msg_get_domain(msg);
699 int16_t source_id = log_msg_get_source_id(msg);
700
701 const char *sname = source_id >= 0 ? log_source_name_get(domain_id, source_id) : NULL;
702 size_t plen, dlen;
703 uint8_t *package = log_msg_get_package(msg, &plen);
704 uint8_t *data = log_msg_get_data(msg, &dlen);
705
706 log_output_process(output, timestamp, NULL, sname, (k_tid_t)log_msg_get_tid(msg), level,
707 plen > 0 ? package : NULL, data, dlen, flags);
708 }
709
log_output_dropped_process(const struct log_output * output,uint32_t cnt)710 void log_output_dropped_process(const struct log_output *output, uint32_t cnt)
711 {
712 char buf[5];
713 int len;
714 static const char prefix[] = DROPPED_COLOR_PREFIX "--- ";
715 static const char postfix[] =
716 " messages dropped ---\r\n" DROPPED_COLOR_POSTFIX;
717 log_output_func_t outf = output->func;
718
719 cnt = MIN(cnt, 9999);
720 len = snprintk(buf, sizeof(buf), "%d", cnt);
721
722 log_output_write(outf, (uint8_t *)prefix, sizeof(prefix) - 1, output->control_block->ctx);
723 log_output_write(outf, buf, len, output->control_block->ctx);
724 log_output_write(outf, (uint8_t *)postfix, sizeof(postfix) - 1, output->control_block->ctx);
725 }
726
log_output_timestamp_freq_set(uint32_t frequency)727 void log_output_timestamp_freq_set(uint32_t frequency)
728 {
729 timestamp_div = 1U;
730 /* There is no point to have frequency higher than 1MHz (ns are not
731 * printed) and too high frequency leads to overflows in calculations.
732 */
733 while (frequency > 1000000) {
734 frequency /= 2U;
735 timestamp_div *= 2U;
736 }
737
738 freq = frequency;
739 }
740
log_output_timestamp_to_us(log_timestamp_t timestamp)741 uint64_t log_output_timestamp_to_us(log_timestamp_t timestamp)
742 {
743 timestamp /= timestamp_div;
744
745 return ((uint64_t) timestamp * 1000000U) / freq;
746 }
747
