1 /*
2 * Copyright (c) 2018 Nordic Semiconductor ASA
3 * Copyright (c) 2023 Meta
4 *
5 * SPDX-License-Identifier: Apache-2.0
6 */
7
8 #include <zephyr/logging/log_backend.h>
9 #include <zephyr/logging/log_core.h>
10 #include <zephyr/logging/log_output.h>
11 #include <zephyr/logging/log_output_dict.h>
12 #include <zephyr/logging/log_backend_std.h>
13 #include <zephyr/logging/log.h>
14 #include <zephyr/device.h>
15 #include <zephyr/drivers/uart.h>
16 #include <zephyr/sys/util_macro.h>
17 #include <zephyr/sys/__assert.h>
18 #include <zephyr/pm/device.h>
19 #include <zephyr/pm/device_runtime.h>
20 LOG_MODULE_REGISTER(log_uart);
21
22 struct lbu_data {
23 struct k_sem sem;
24 uint32_t log_format_current;
25 volatile bool in_panic;
26 bool use_async;
27 };
28
29 struct lbu_cb_ctx {
30 const struct log_output *output;
31 #if DT_HAS_CHOSEN(zephyr_log_uart)
32 const struct device *uart_dev;
33 #endif
34 struct lbu_data *data;
35 };
36
37 #define LBU_UART_DEV(ctx) \
38 COND_CODE_1(DT_HAS_CHOSEN(zephyr_log_uart), (ctx->uart_dev), \
39 (DEVICE_DT_GET(DT_CHOSEN(zephyr_console))))
40
41 /* Fixed size to avoid auto-added trailing '\0'.
42 * Used if CONFIG_LOG_BACKEND_UART_OUTPUT_DICTIONARY_HEX.
43 */
44 static const char LOG_HEX_SEP[10] = "##ZLOGV1##";
45
uart_callback(const struct device * dev,struct uart_event * evt,void * user_data)46 static void uart_callback(const struct device *dev,
47 struct uart_event *evt,
48 void *user_data)
49 {
50 const struct lbu_cb_ctx *ctx = user_data;
51 struct lbu_data *data = ctx->data;
52
53 ARG_UNUSED(dev);
54
55 switch (evt->type) {
56 case UART_TX_DONE:
57 k_sem_give(&data->sem);
58 break;
59 default:
60 break;
61 }
62 }
63
dict_char_out_hex(const struct device * uart_dev,uint8_t * data,size_t length)64 static void dict_char_out_hex(const struct device *uart_dev, uint8_t *data, size_t length)
65 {
66 for (size_t i = 0; i < length; i++) {
67 char c;
68 uint8_t x;
69
70 /* upper 8-bit */
71 x = data[i] >> 4;
72 (void)hex2char(x, &c);
73 uart_poll_out(uart_dev, c);
74
75 /* lower 8-bit */
76 x = data[i] & 0x0FU;
77 (void)hex2char(x, &c);
78 uart_poll_out(uart_dev, c);
79 }
80 }
81
char_out(uint8_t * data,size_t length,void * ctx)82 static int char_out(uint8_t *data, size_t length, void *ctx)
83 {
84 int err;
85 const struct lbu_cb_ctx *cb_ctx = ctx;
86 struct lbu_data *lb_data = cb_ctx->data;
87 const struct device *uart_dev = LBU_UART_DEV(cb_ctx);
88
89 if (pm_device_runtime_get(uart_dev) < 0) {
90 /* Enabling the UART instance has failed but this
91 * function MUST return the number of bytes consumed.
92 */
93 return length;
94 }
95
96 if (IS_ENABLED(CONFIG_LOG_BACKEND_UART_OUTPUT_DICTIONARY_HEX)) {
97 dict_char_out_hex(uart_dev, data, length);
98 goto cleanup;
99 }
100
101 if (!IS_ENABLED(CONFIG_LOG_BACKEND_UART_ASYNC) || lb_data->in_panic ||
102 !lb_data->use_async) {
103 for (size_t i = 0; i < length; i++) {
104 uart_poll_out(uart_dev, data[i]);
105 }
106 goto cleanup;
107 }
108
109 err = uart_tx(uart_dev, data, length, SYS_FOREVER_US);
110 __ASSERT_NO_MSG(err == 0);
111
112 err = k_sem_take(&lb_data->sem, K_FOREVER);
113 __ASSERT_NO_MSG(err == 0);
114
115 (void)err;
116 cleanup:
117 /* Use async put to avoid useless device suspension/resumption
118 * when tranmiting chain of chars.
119 * As errors cannot be returned, ignore the return value
120 */
121 (void)pm_device_runtime_put_async(uart_dev, K_MSEC(1));
122
123 return length;
124 }
125
process(const struct log_backend * const backend,union log_msg_generic * msg)126 static void process(const struct log_backend *const backend,
127 union log_msg_generic *msg)
128 {
129 const struct lbu_cb_ctx *ctx = backend->cb->ctx;
130 struct lbu_data *data = ctx->data;
131 uint32_t flags = log_backend_std_get_flags();
132 log_format_func_t log_output_func = log_format_func_t_get(data->log_format_current);
133
134 log_output_func(ctx->output, &msg->log, flags);
135 }
136
format_set(const struct log_backend * const backend,uint32_t log_type)137 static int format_set(const struct log_backend *const backend, uint32_t log_type)
138 {
139 const struct lbu_cb_ctx *ctx = backend->cb->ctx;
140 struct lbu_data *data = ctx->data;
141
142 data->log_format_current = log_type;
143
144 return 0;
145 }
146
log_backend_uart_init(struct log_backend const * const backend)147 static void log_backend_uart_init(struct log_backend const *const backend)
148 {
149 const struct lbu_cb_ctx *ctx = backend->cb->ctx;
150 const struct device *uart_dev = LBU_UART_DEV(ctx);
151 struct lbu_data *data = ctx->data;
152
153 __ASSERT_NO_MSG(device_is_ready(uart_dev));
154
155 log_output_ctx_set(ctx->output, (void *)ctx);
156
157 if (IS_ENABLED(CONFIG_LOG_BACKEND_UART_OUTPUT_DICTIONARY_HEX)) {
158 /* Print a separator so the output can be fed into
159 * log parser directly. This is useful when capturing
160 * from UART directly where there might be other output
161 * (e.g. bootloader).
162 */
163 for (int i = 0; i < sizeof(LOG_HEX_SEP); i++) {
164 uart_poll_out(uart_dev, LOG_HEX_SEP[i]);
165 }
166
167 return;
168 }
169
170 if (IS_ENABLED(CONFIG_LOG_BACKEND_UART_ASYNC)) {
171 int err = uart_callback_set(uart_dev, uart_callback, (void *)ctx);
172
173 if (err == 0) {
174 data->use_async = true;
175 k_sem_init(&data->sem, 0, 1);
176 } else {
177 LOG_WRN("Failed to initialize asynchronous mode (err:%d). "
178 "Fallback to polling.",
179 err);
180 }
181 }
182 }
183
panic(struct log_backend const * const backend)184 static void panic(struct log_backend const *const backend)
185 {
186 const struct lbu_cb_ctx *ctx = backend->cb->ctx;
187 struct lbu_data *data = ctx->data;
188 const struct device *uart_dev = LBU_UART_DEV(ctx);
189
190 /* Ensure that the UART device is in active mode */
191 #if defined(CONFIG_PM_DEVICE_RUNTIME)
192 (void)pm_device_runtime_get(uart_dev);
193 #elif defined(CONFIG_PM_DEVICE)
194 enum pm_device_state pm_state;
195 int rc;
196
197 rc = pm_device_state_get(uart_dev, &pm_state);
198 if ((rc == 0) && (pm_state == PM_DEVICE_STATE_SUSPENDED)) {
199 pm_device_action_run(uart_dev, PM_DEVICE_ACTION_RESUME);
200 }
201 #else
202 ARG_UNUSED(uart_dev);
203 #endif /* CONFIG_PM_DEVICE */
204
205 data->in_panic = true;
206 log_backend_std_panic(ctx->output);
207 }
208
dropped(const struct log_backend * const backend,uint32_t cnt)209 static void dropped(const struct log_backend *const backend, uint32_t cnt)
210 {
211 const struct lbu_cb_ctx *ctx = backend->cb->ctx;
212
213 if (IS_ENABLED(CONFIG_LOG_BACKEND_UART_OUTPUT_DICTIONARY)) {
214 log_dict_output_dropped_process(ctx->output, cnt);
215 } else {
216 log_backend_std_dropped(ctx->output, cnt);
217 }
218 }
219
220 const struct log_backend_api log_backend_uart_api = {
221 .process = process,
222 .panic = panic,
223 .init = log_backend_uart_init,
224 .dropped = IS_ENABLED(CONFIG_LOG_MODE_IMMEDIATE) ? NULL : dropped,
225 .format_set = format_set,
226 };
227
228 #define LBU_DEFINE(node_id, ...) \
229 static uint8_t lbu_buffer##__VA_ARGS__[CONFIG_LOG_BACKEND_UART_BUFFER_SIZE]; \
230 LOG_OUTPUT_DEFINE(lbu_output##__VA_ARGS__, char_out, lbu_buffer##__VA_ARGS__, \
231 CONFIG_LOG_BACKEND_UART_BUFFER_SIZE); \
232 \
233 static struct lbu_data lbu_data##__VA_ARGS__ = { \
234 .log_format_current = CONFIG_LOG_BACKEND_UART_OUTPUT_DEFAULT, \
235 }; \
236 \
237 static const struct lbu_cb_ctx lbu_cb_ctx##__VA_ARGS__ = { \
238 .output = &lbu_output##__VA_ARGS__, \
239 COND_CODE_0(NUM_VA_ARGS_LESS_1(_, ##__VA_ARGS__), (), \
240 (.uart_dev = DEVICE_DT_GET(node_id),)) \
241 .data = &lbu_data##__VA_ARGS__, \
242 }; \
243 \
244 LOG_BACKEND_DEFINE(log_backend_uart##__VA_ARGS__, log_backend_uart_api, \
245 IS_ENABLED(CONFIG_LOG_BACKEND_UART_AUTOSTART), \
246 (void *)&lbu_cb_ctx##__VA_ARGS__);
247
248 #if DT_HAS_CHOSEN(zephyr_log_uart)
249 #define LBU_PHA_FN(node_id, prop, idx) LBU_DEFINE(DT_PHANDLE_BY_IDX(node_id, prop, idx), idx)
250 DT_FOREACH_PROP_ELEM_SEP(DT_CHOSEN(zephyr_log_uart), uarts, LBU_PHA_FN, ());
251 #else
252 LBU_DEFINE(DT_CHOSEN(zephyr_console));
253 #endif
254
