1 /*
2 * Copyright (c) 2021 Nordic Semiconductor
3 *
4 * SPDX-License-Identifier: Apache-2.0
5 */
6
7
8 #include <zephyr/tc_util.h>
9 #include <stdbool.h>
10 #include <zephyr/kernel.h>
11 #include <zephyr/toolchain.h>
12 #include <zephyr/ztest.h>
13 #include <zephyr/logging/log_backend.h>
14 #include <zephyr/logging/log_ctrl.h>
15 #include <zephyr/logging/log.h>
16
17 #define LOG_MODULE_NAME test
18 LOG_MODULE_REGISTER(LOG_MODULE_NAME);
19
20 struct backend_context {
21 uint32_t cnt;
22 const char *exp_str[10];
23 uint32_t delay;
24 bool active;
25 struct k_timer timer;
26 };
27
cbprintf_callback(int c,void * ctx)28 static int cbprintf_callback(int c, void *ctx)
29 {
30 char **p = ctx;
31
32 **p = c;
33 (*p)++;
34
35 return c;
36 }
37
backend_process(const struct log_backend * const backend,union log_msg_generic * msg)38 static void backend_process(const struct log_backend *const backend,
39 union log_msg_generic *msg)
40 {
41 char str[100];
42 char *pstr = str;
43 struct backend_context *context = (struct backend_context *)backend->cb->ctx;
44 size_t len;
45 uint8_t *p = log_msg_get_package(&msg->log, &len);
46
47 (void)len;
48 int slen = cbpprintf(cbprintf_callback, &pstr, p);
49
50 str[slen] = '\0';
51
52 zassert_equal(strcmp(str, context->exp_str[context->cnt]), 0,
53 "Unexpected string %s (exp:%s)", str, context->exp_str[context->cnt]);
54
55 context->cnt++;
56 }
57
panic(const struct log_backend * const backend)58 static void panic(const struct log_backend *const backend)
59 {
60 ARG_UNUSED(backend);
61 }
62
expire_cb(struct k_timer * timer)63 static void expire_cb(struct k_timer *timer)
64 {
65 void *ctx = k_timer_user_data_get(timer);
66 struct backend_context *context = (struct backend_context *)ctx;
67
68 context->active = true;
69 }
70
backend_init(const struct log_backend * const backend)71 static void backend_init(const struct log_backend *const backend)
72 {
73 struct backend_context *context = (struct backend_context *)backend->cb->ctx;
74
75 k_timer_init(&context->timer, expire_cb, NULL);
76 k_timer_user_data_set(&context->timer, (void *)context);
77 k_timer_start(&context->timer, K_MSEC(context->delay), K_NO_WAIT);
78 }
79
backend_is_ready(const struct log_backend * const backend)80 static int backend_is_ready(const struct log_backend *const backend)
81 {
82 struct backend_context *context = (struct backend_context *)backend->cb->ctx;
83
84 return context->active ? 0 : -EBUSY;
85 }
86
87 static const struct log_backend_api backend_api = {
88 .process = backend_process,
89 .init = backend_init,
90 .is_ready = backend_is_ready,
91 .panic = panic
92 };
93
94 static struct backend_context context1 = {
95 .delay = 500
96 };
97
98 static struct backend_context context2 = {
99 .delay = 1000,
100 };
101
102 LOG_BACKEND_DEFINE(backend1, backend_api, true, &context1);
103 LOG_BACKEND_DEFINE(backend2, backend_api, true, &context2);
104
105 /* Test is using two backends which are configured to be autostarted but have
106 * prolonged initialization. Backend1 starts earlier.
107 *
108 * Logging does not process logs until at least one backend is ready so once
109 * backend1 is ready first log message is processed. Since backend2 is not yet
110 * ready it will not receive this message. Second message is created when
111 * both backends are initialized so both receives the message.
112 */
ZTEST(log_backend_init,test_log_backends_initialization)113 ZTEST(log_backend_init, test_log_backends_initialization)
114 {
115 int cnt;
116
117 STRUCT_SECTION_COUNT(log_backend, &cnt);
118 if (cnt != 2) {
119 /* Other backends should not be enabled. */
120 ztest_test_skip();
121 }
122
123 context1.cnt = 0;
124 context2.cnt = 0;
125
126 context1.exp_str[0] = "test1";
127 context1.exp_str[1] = "test2";
128
129 context2.exp_str[0] = "test2";
130
131 LOG_INF("test1");
132
133 /* Backends are not yet active. */
134 zassert_false(context1.active);
135 zassert_false(context2.active);
136
137 k_msleep(context2.delay + 100);
138
139 zassert_true(context1.active);
140 zassert_true(context2.active);
141
142 LOG_INF("test2");
143
144 k_msleep(1100);
145
146 /* Backend1 gets both messages but backend2 gets only second message
147 * because when first was processed it was not yet active.
148 */
149 zassert_equal(context1.cnt, 2, "Unexpected value:%d (exp: %d)", context1.cnt, 2);
150 zassert_equal(context2.cnt, 1);
151 }
152
153 ZTEST_SUITE(log_backend_init, NULL, NULL, NULL, NULL, NULL);
154
