Skip to content

Commit 7bae594

Browse files
nordic-krchnashif
nordic-krch
authored and
nashif
committed
shell: Add support for logging v2
Extended shell to support logging v2. Signed-off-by: Krzysztof Chruscinski <[email protected]>
1 parent bb64419 commit 7bae594

File tree

2 files changed

+184
-28
lines changed

2 files changed

+184
-28
lines changed

‎include/shell/shell_log_backend.h‎

Lines changed: 30 additions & 13 deletions
Original file line numberDiff line numberDiff line change
@@ -10,6 +10,7 @@
1010
#include <zephyr.h>
1111
#include <logging/log_backend.h>
1212
#include <logging/log_output.h>
13+
#include <sys/mpsc_pbuf.h>
1314
#include <sys/atomic.h>
1415
#ifdef __cplusplus
1516
extern "C" {
@@ -38,6 +39,8 @@ struct shell_log_backend {
3839
const struct log_output *log_output;
3940
struct shell_log_backend_control_block *control_block;
4041
uint32_t timeout;
42+
const struct mpsc_pbuf_buffer_config *mpsc_buffer_config;
43+
struct mpsc_pbuf_buffer *mpsc_buffer;
4144
};
4245

4346
/** @brief Shell log backend message structure. */
@@ -65,19 +68,33 @@ int z_shell_log_backend_output_func(uint8_t *data, size_t length, void *ctx);
6568
* @param _name Shell name.
6669
*/
6770
#ifdef CONFIG_SHELL_LOG_BACKEND
68-
#define Z_SHELL_LOG_BACKEND_DEFINE(_name, _buf, _size, _queue_size, _timeout) \
69-
LOG_BACKEND_DEFINE(_name##_backend, log_backend_shell_api, false); \
70-
K_MSGQ_DEFINE(_name##_msgq, sizeof(struct shell_log_backend_msg), \
71-
_queue_size, sizeof(void *)); \
72-
LOG_OUTPUT_DEFINE(_name##_log_output, z_shell_log_backend_output_func, \
73-
_buf, _size); \
74-
static struct shell_log_backend_control_block _name##_control_block; \
75-
static const struct shell_log_backend _name##_log_backend = { \
76-
.backend = &_name##_backend, \
77-
.msgq = &_name##_msgq, \
78-
.log_output = &_name##_log_output, \
79-
.control_block = &_name##_control_block, \
80-
.timeout = _timeout \
71+
#define Z_SHELL_LOG_BACKEND_DEFINE(_name, _buf, _size, _queue_size, _timeout) \
72+
LOG_BACKEND_DEFINE(_name##_backend, log_backend_shell_api, false); \
73+
K_MSGQ_DEFINE(_name##_msgq, sizeof(struct shell_log_backend_msg), \
74+
_queue_size, sizeof(void *)); \
75+
LOG_OUTPUT_DEFINE(_name##_log_output, z_shell_log_backend_output_func,\
76+
_buf, _size); \
77+
static struct shell_log_backend_control_block _name##_control_block; \
78+
static uint32_t _name##_buf[128]; \
79+
const struct mpsc_pbuf_buffer_config _name##_mpsc_buffer_config = { \
80+
.buf = _name##_buf, \
81+
.size = ARRAY_SIZE(_name##_buf), \
82+
.notify_drop = NULL, \
83+
.get_wlen = log_msg2_generic_get_wlen, \
84+
.flags = MPSC_PBUF_MODE_OVERWRITE, \
85+
}; \
86+
struct mpsc_pbuf_buffer _name##_mpsc_buffer; \
87+
static const struct shell_log_backend _name##_log_backend = { \
88+
.backend = &_name##_backend, \
89+
.msgq = IS_ENABLED(CONFIG_LOG_MODE_DEFERRED) ? \
90+
&_name##_msgq : NULL, \
91+
.log_output = &_name##_log_output, \
92+
.control_block = &_name##_control_block, \
93+
.timeout = _timeout, \
94+
.mpsc_buffer_config = IS_ENABLED(CONFIG_LOG2_MODE_DEFERRED) ? \
95+
&_name##_mpsc_buffer_config : NULL, \
96+
.mpsc_buffer = IS_ENABLED(CONFIG_LOG2_MODE_DEFERRED) ? \
97+
&_name##_mpsc_buffer : NULL, \
8198
}
8299

83100
#define Z_SHELL_LOG_BACKEND_PTR(_name) (&_name##_log_backend)

‎subsys/shell/shell_log_backend.c‎

Lines changed: 154 additions & 15 deletions
Original file line numberDiff line numberDiff line change
@@ -9,6 +9,8 @@
99
#include "shell_ops.h"
1010
#include <logging/log_ctrl.h>
1111

12+
static bool process_msg2_from_buffer(const struct shell *shell);
13+
1214
int z_shell_log_backend_output_func(uint8_t *data, size_t length, void *ctx)
1315
{
1416
z_shell_print_stream(ctx, data, length);
@@ -29,6 +31,11 @@ void z_shell_log_backend_enable(const struct shell_log_backend *backend,
2931
err = shell->iface->api->enable(shell->iface, true);
3032
}
3133

34+
if (IS_ENABLED(CONFIG_LOG2_MODE_DEFERRED)) {
35+
mpsc_pbuf_init(backend->mpsc_buffer,
36+
backend->mpsc_buffer_config);
37+
}
38+
3239
if (err == 0) {
3340
log_backend_enable(backend->backend, ctx, init_log_level);
3441
log_output_ctx_set(backend->log_output, ctx);
@@ -141,16 +148,11 @@ static void msg_process(const struct log_output *log_output,
141148

142149
bool z_shell_log_backend_process(const struct shell_log_backend *backend)
143150
{
144-
uint32_t dropped;
145151
const struct shell *shell =
146152
(const struct shell *)backend->backend->cb->ctx;
153+
uint32_t dropped;
147154
bool colors = IS_ENABLED(CONFIG_SHELL_VT100_COLORS) &&
148155
shell->ctx->internal.flags.use_colors;
149-
struct log_msg *msg = msg_from_fifo(backend);
150-
151-
if (!msg) {
152-
return false;
153-
}
154156

155157
dropped = atomic_set(&backend->control_block->dropped_cnt, 0);
156158
if (dropped) {
@@ -168,6 +170,15 @@ bool z_shell_log_backend_process(const struct shell_log_backend *backend)
168170
}
169171
}
170172

173+
if (IS_ENABLED(CONFIG_LOG2_MODE_DEFERRED)) {
174+
return process_msg2_from_buffer(shell);
175+
}
176+
177+
struct log_msg *msg = msg_from_fifo(backend);
178+
179+
if (!msg) {
180+
return false;
181+
}
171182
msg_process(shell->log_backend->log_output, msg, colors);
172183

173184
return true;
@@ -234,7 +245,8 @@ static void put_sync_string(const struct log_backend *const backend,
234245

235246
static void put_sync_hexdump(const struct log_backend *const backend,
236247
struct log_msg_ids src_level, uint32_t timestamp,
237-
const char *metadata, const uint8_t *data, uint32_t length)
248+
const char *metadata, const uint8_t *data,
249+
uint32_t length)
238250
{
239251
const struct shell *shell = (const struct shell *)backend->cb->ctx;
240252
uint32_t key;
@@ -250,8 +262,8 @@ static void put_sync_hexdump(const struct log_backend *const backend,
250262
if (!z_flag_cmd_ctx_get(shell)) {
251263
z_shell_cmd_line_erase(shell);
252264
}
253-
log_output_hexdump(shell->log_backend->log_output, src_level, timestamp,
254-
metadata, data, length, flags);
265+
log_output_hexdump(shell->log_backend->log_output, src_level,
266+
timestamp, metadata, data, length, flags);
255267
if (!z_flag_cmd_ctx_get(shell)) {
256268
z_shell_print_prompt_and_cmd(shell);
257269
}
@@ -271,7 +283,7 @@ static void panic(const struct log_backend *const backend)
271283

272284
if (err == 0) {
273285
shell->log_backend->control_block->state =
274-
SHELL_LOG_BACKEND_PANIC;
286+
SHELL_LOG_BACKEND_PANIC;
275287

276288
/* Move to the start of next line. */
277289
z_shell_multiline_data_calc(&shell->ctx->vt100_ctx.cons,
@@ -281,8 +293,15 @@ static void panic(const struct log_backend *const backend)
281293
z_shell_op_cursor_horiz_move(shell,
282294
-shell->ctx->vt100_ctx.cons.cur_x);
283295

284-
while (z_shell_log_backend_process(shell->log_backend)) {
285-
/* empty */
296+
if (IS_ENABLED(CONFIG_LOG2_MODE_DEFERRED)) {
297+
while (process_msg2_from_buffer(shell)) {
298+
/* empty */
299+
}
300+
} else if (IS_ENABLED(CONFIG_LOG_MODE_DEFERRED)) {
301+
while (z_shell_log_backend_process(
302+
shell->log_backend)) {
303+
/* empty */
304+
}
286305
}
287306
} else {
288307
z_shell_log_backend_disable(shell->log_backend);
@@ -298,11 +317,131 @@ static void dropped(const struct log_backend *const backend, uint32_t cnt)
298317
atomic_add(&log_backend->control_block->dropped_cnt, cnt);
299318
}
300319

320+
static void copy_to_pbuffer(struct mpsc_pbuf_buffer *mpsc_buffer,
321+
union log_msg2_generic *msg, uint32_t timeout)
322+
{
323+
size_t wlen;
324+
union mpsc_pbuf_generic *dst;
325+
326+
wlen = log_msg2_generic_get_wlen((union mpsc_pbuf_generic *)msg);
327+
dst = mpsc_pbuf_alloc(mpsc_buffer, wlen, K_MSEC(timeout));
328+
if (!dst) {
329+
/* No space to store the log */
330+
return;
331+
}
332+
333+
/* First word contains intenal mpsc packet flags and when copying
334+
* those flags must be omitted.
335+
*/
336+
uint8_t *dst_data = (uint8_t *)dst + sizeof(struct mpsc_pbuf_hdr);
337+
uint8_t *src_data = (uint8_t *)msg + sizeof(struct mpsc_pbuf_hdr);
338+
size_t hdr_wlen = ceiling_fraction(sizeof(struct mpsc_pbuf_hdr),
339+
sizeof(uint32_t));
340+
341+
dst->hdr.data = msg->buf.hdr.data;
342+
memcpy(dst_data, src_data, (wlen - hdr_wlen) * sizeof(uint32_t));
343+
344+
mpsc_pbuf_commit(mpsc_buffer, dst);
345+
}
346+
347+
static void process_log_msg2(const struct shell *shell,
348+
const struct log_output *log_output,
349+
union log_msg2_generic *msg,
350+
bool locked, bool colors)
351+
{
352+
unsigned int key;
353+
uint32_t flags = LOG_OUTPUT_FLAG_LEVEL |
354+
LOG_OUTPUT_FLAG_TIMESTAMP |
355+
LOG_OUTPUT_FLAG_FORMAT_TIMESTAMP;
356+
357+
if (colors) {
358+
flags |= LOG_OUTPUT_FLAG_COLORS;
359+
}
360+
361+
if (locked) {
362+
key = irq_lock();
363+
if (!z_flag_cmd_ctx_get(shell)) {
364+
z_shell_cmd_line_erase(shell);
365+
}
366+
}
367+
368+
log_output_msg2_process(log_output, &msg->log, flags);
369+
370+
if (locked) {
371+
if (!z_flag_cmd_ctx_get(shell)) {
372+
z_shell_print_prompt_and_cmd(shell);
373+
}
374+
irq_unlock(key);
375+
}
376+
}
377+
378+
static bool process_msg2_from_buffer(const struct shell *shell)
379+
{
380+
const struct shell_log_backend *log_backend = shell->log_backend;
381+
struct mpsc_pbuf_buffer *mpsc_buffer = log_backend->mpsc_buffer;
382+
const struct log_output *log_output = log_backend->log_output;
383+
union log_msg2_generic *msg;
384+
bool colors = IS_ENABLED(CONFIG_SHELL_VT100_COLORS) &&
385+
shell->ctx->internal.flags.use_colors;
386+
387+
msg = (union log_msg2_generic *)mpsc_pbuf_claim(mpsc_buffer);
388+
if (!msg) {
389+
return false;
390+
}
391+
392+
process_log_msg2(shell, log_output, msg, false, colors);
393+
394+
mpsc_pbuf_free(mpsc_buffer, &msg->buf);
395+
396+
return true;
397+
}
398+
399+
static void log2_process(const struct log_backend *const backend,
400+
union log_msg2_generic *msg)
401+
{
402+
const struct shell *shell = (const struct shell *)backend->cb->ctx;
403+
const struct shell_log_backend *log_backend = shell->log_backend;
404+
struct mpsc_pbuf_buffer *mpsc_buffer = log_backend->mpsc_buffer;
405+
const struct log_output *log_output = log_backend->log_output;
406+
bool colors = IS_ENABLED(CONFIG_SHELL_VT100_COLORS) &&
407+
shell->ctx->internal.flags.use_colors;
408+
struct k_poll_signal *signal;
409+
410+
switch (shell->log_backend->control_block->state) {
411+
case SHELL_LOG_BACKEND_ENABLED:
412+
if (IS_ENABLED(CONFIG_LOG_IMMEDIATE)) {
413+
process_log_msg2(shell, log_output, msg, true, colors);
414+
} else {
415+
copy_to_pbuffer(mpsc_buffer, msg,
416+
log_backend->timeout);
417+
418+
if (IS_ENABLED(CONFIG_MULTITHREADING)) {
419+
signal =
420+
&shell->ctx->signals[SHELL_SIGNAL_LOG_MSG];
421+
k_poll_signal_raise(signal, 0);
422+
}
423+
}
424+
425+
break;
426+
case SHELL_LOG_BACKEND_PANIC:
427+
z_shell_cmd_line_erase(shell);
428+
process_log_msg2(shell, log_output, msg, true, colors);
429+
430+
break;
431+
432+
case SHELL_LOG_BACKEND_DISABLED:
433+
__fallthrough;
434+
default:
435+
break;
436+
}
437+
}
438+
301439
const struct log_backend_api log_backend_shell_api = {
302-
.put = IS_ENABLED(CONFIG_LOG_IMMEDIATE) ? NULL : put,
303-
.put_sync_string = IS_ENABLED(CONFIG_LOG_IMMEDIATE) ?
440+
.process = IS_ENABLED(CONFIG_LOG2) ? log2_process : NULL,
441+
.put = IS_ENABLED(CONFIG_LOG_MODE_DEFERRED) ? put : NULL,
442+
.put_sync_string = IS_ENABLED(CONFIG_LOG_MODE_IMMEDIATE) ?
304443
put_sync_string : NULL,
305-
.put_sync_hexdump = IS_ENABLED(CONFIG_LOG_IMMEDIATE) ?
444+
.put_sync_hexdump = IS_ENABLED(CONFIG_LOG_MODE_IMMEDIATE) ?
306445
put_sync_hexdump : NULL,
307446
.dropped = dropped,
308447
.panic = panic,

0 commit comments

Comments
 (0)