1 /* LOG unit tests
2 
3    This example code is in the Public Domain (or CC0 licensed, at your option.)
4 
5    Unless required by applicable law or agreed to in writing, this
6    software is distributed on an "AS IS" BASIS, WITHOUT WARRANTIES OR
7    CONDITIONS OF ANY KIND, either express or implied.
8 */
9 #define CATCH_CONFIG_MAIN
10 #include <cstdio>
11 #include <regex>
12 #include <iostream>
13 #include "esp_log.h"
14 
15 #include "catch.hpp"
16 
17 using namespace std;
18 
19 static const char *TEST_TAG = "test";
20 
21 class BasicLogFixture {
22 public:
23     static const size_t BUFFER_SIZE = 4096;
24 
BasicLogFixture(esp_log_level_t log_level=ESP_LOG_VERBOSE)25     BasicLogFixture(esp_log_level_t log_level = ESP_LOG_VERBOSE)
26     {
27         std::memset(print_buffer, 0, BUFFER_SIZE);
28         esp_log_level_set("*", log_level);
29     }
30 
~BasicLogFixture()31     virtual ~BasicLogFixture()
32     {
33         esp_log_level_set("*", ESP_LOG_INFO);
34     }
35 
get_print_buffer_string() const36     string get_print_buffer_string() const
37     {
38         return string(print_buffer);
39     }
40 
reset_buffer()41     void reset_buffer()
42     {
43         std::memset(print_buffer, 0, BUFFER_SIZE);
44         additional_reset();
45     }
46 
47 protected:
48     char print_buffer [BUFFER_SIZE];
49 
additional_reset()50     virtual void additional_reset() { }
51 };
52 
53 struct PrintFixture : BasicLogFixture {
PrintFixturePrintFixture54     PrintFixture(esp_log_level_t log_level = ESP_LOG_VERBOSE) : BasicLogFixture(log_level)
55     {
56         if (instance != nullptr) {
57             throw exception();
58         }
59 
60         instance = this;
61 
62         old_vprintf = esp_log_set_vprintf(print_callback);
63     }
64 
~PrintFixturePrintFixture65     virtual ~PrintFixture()
66     {
67         esp_log_set_vprintf(old_vprintf);
68         instance = nullptr;
69     }
70 
71 private:
print_callbackPrintFixture72     static int print_callback(const char *format, va_list args)
73     {
74         return instance->print_to_buffer(format, args);
75     }
76 
print_to_bufferPrintFixture77     int print_to_buffer(const char *format, va_list args)
78     {
79         int ret = vsnprintf(print_buffer, BUFFER_SIZE, format, args);
80         return ret;
81     }
82 
83     static PrintFixture *instance;
84 
85     vprintf_like_t old_vprintf;
86 };
87 
88 struct PutcFixture : BasicLogFixture {
PutcFixturePutcFixture89     PutcFixture(esp_log_level_t log_level = ESP_LOG_VERBOSE) : BasicLogFixture(log_level), counter(0)
90     {
91         if (instance != nullptr) {
92             throw exception();
93         }
94 
95         esp_rom_install_channel_putc(0, putc_callback);
96 
97         instance = this;
98     }
99 
~PutcFixturePutcFixture100     ~PutcFixture()
101     {
102         esp_rom_install_uart_printf();
103         instance = nullptr;
104     }
105 
additional_resetPutcFixture106     void additional_reset() override
107     {
108         counter = 0;
109     }
110 
111     size_t counter;
112 
113 private:
putc_callbackPutcFixture114     static void putc_callback(char c)
115     {
116         return instance->putc_to_buffer(c);
117     }
118 
putc_to_bufferPutcFixture119     void putc_to_buffer(char c)
120     {
121         print_buffer[counter++] = c;
122     }
123 
124     static PutcFixture *instance;
125 };
126 
127 PrintFixture *PrintFixture::instance = nullptr;
128 PutcFixture *PutcFixture::instance = nullptr;
129 
130 TEST_CASE("verbose log level")
131 {
132     PrintFixture fix(ESP_LOG_VERBOSE);
133     const std::regex test_print("V \\([0-9]*\\) test: verbose", std::regex::ECMAScript);
134 
135     ESP_LOGV(TEST_TAG, "verbose");
136     CHECK(regex_search(fix.get_print_buffer_string(), test_print) == true);
137 }
138 
139 TEST_CASE("debug log level")
140 {
141     PrintFixture fix(ESP_LOG_DEBUG);
142     const std::regex test_print("D \\([0-9]*\\) test: debug", std::regex::ECMAScript);
143 
144     ESP_LOGD(TEST_TAG, "debug");
145     CHECK(regex_search(fix.get_print_buffer_string(), test_print) == true);
146 }
147 
148 TEST_CASE("info log level")
149 {
150     PrintFixture fix(ESP_LOG_INFO);
151     const std::regex test_print("I \\([0-9]*\\) test: info", std::regex::ECMAScript);
152 
153     ESP_LOGI(TEST_TAG, "info");
154     CHECK(regex_search(fix.get_print_buffer_string(), test_print) == true);
155 }
156 
157 TEST_CASE("warn log level")
158 {
159     PrintFixture fix(ESP_LOG_WARN);
160     const std::regex test_print("W \\([0-9]*\\) test: warn", std::regex::ECMAScript);
161 
162     ESP_LOGW(TEST_TAG, "warn");
163     CHECK(regex_search(fix.get_print_buffer_string(), test_print) == true);
164 }
165 
166 TEST_CASE("error log level")
167 {
168     PrintFixture fix(ESP_LOG_ERROR);
169     const std::regex test_print("E \\([0-9]*\\) test: error", std::regex::ECMAScript);
170 
171     ESP_LOGE(TEST_TAG, "error");
172     CHECK(regex_search(fix.get_print_buffer_string(), test_print) == true);
173 }
174 
175 TEST_CASE("changing log level")
176 {
177     PrintFixture fix(ESP_LOG_INFO);
178     const std::regex test_print("I \\([0-9]*\\) test: must indeed be printed", std::regex::ECMAScript);
179 
180     ESP_LOGI(TEST_TAG, "must indeed be printed");
181     CHECK(regex_search(fix.get_print_buffer_string(), test_print) == true);
182 
183     fix.reset_buffer();
184     esp_log_level_set(TEST_TAG, ESP_LOG_WARN);
185 
186     ESP_LOGI(TEST_TAG, "must not be printed");
187     CHECK(fix.get_print_buffer_string().size() == 0);
188 
189     fix.reset_buffer();
190     esp_log_level_set(TEST_TAG, ESP_LOG_INFO);
191 
192     ESP_LOGI(TEST_TAG, "must indeed be printed");
193     CHECK(regex_search(fix.get_print_buffer_string(), test_print) == true);
194 }
195 
196 TEST_CASE("log buffer")
197 {
198     PrintFixture fix(ESP_LOG_INFO);
199     const uint8_t buffer[] = {
200         0x01, 0x02, 0x03, 0x04, 0x05, 0x06, 0x07, 0x08,
201         0x11, 0x12, 0x13, 0x14, 0x15, 0x16, 0x17, 0x18,
202     };
203     ESP_LOG_BUFFER_HEX(TEST_TAG, buffer, sizeof(buffer));
204     const std::regex buffer_regex("I \\([0-9]*\\) test: 01 02 03 04 05 06 07 08 11 12 13 14 15 16 17 18", std::regex::ECMAScript);
205     CHECK(regex_search(fix.get_print_buffer_string(), buffer_regex));
206 }
207 
208 TEST_CASE("log bytes > 127")
209 {
210     PrintFixture fix(ESP_LOG_INFO);
211     const uint8_t buffer[] = {
212         0xff, 0x80,
213     };
214     ESP_LOG_BUFFER_HEX(TEST_TAG, buffer, sizeof(buffer));
215     const std::regex buffer_regex("I \\([0-9]*\\) test: ff 80", std::regex::ECMAScript);
216     CHECK(regex_search(fix.get_print_buffer_string(), buffer_regex));
217 }
218 
219 TEST_CASE("log buffer dump")
220 {
221     PrintFixture fix(ESP_LOG_INFO);
222     const uint8_t buffer[] = {
223         0x00, 0x00, 0x00, 0x00, 0x05, 0x06, 0x07, 0x08,
224         0xff, 0xfe, 0xfd, 0xfc, 0xfb, 0xfa, 0xf9, 0xf8
225     };
226     ESP_LOG_BUFFER_HEXDUMP(TEST_TAG, buffer, sizeof(buffer), ESP_LOG_INFO);
227     const std::regex buffer_regex("I \\([0-9]*\\) test: 0x[0-9a-f]+\\s+"
228                                   "00 00 00 00 05 06 07 08  ff fe fd fc fb fa f9 f8 "
229                                   "\\s+|[\\.]{16}|", std::regex::ECMAScript);
230     CHECK(regex_search(fix.get_print_buffer_string(), buffer_regex));
231 }
232 
233 TEST_CASE("rom printf")
234 {
235     PutcFixture fix;
236     int printed_chars = esp_rom_printf("info");
237 
238     CHECK(printed_chars == 4);
239     CHECK(fix.get_print_buffer_string() == "info");
240 }
241 
242 TEST_CASE("early verbose log level")
243 {
244     PutcFixture fix;
245     const std::regex test_print("V \\([0-9]*\\) test: verbose", std::regex::ECMAScript);
246 
247     ESP_EARLY_LOGV(TEST_TAG, "verbose");
248     CHECK(regex_search(fix.get_print_buffer_string(), test_print) == true);
249 }
250 
251 TEST_CASE("early debug log level")
252 {
253     PutcFixture fix;
254     const std::regex test_print("D \\([0-9]*\\) test: debug", std::regex::ECMAScript);
255 
256     ESP_EARLY_LOGD(TEST_TAG, "debug");
257     CHECK(regex_search(fix.get_print_buffer_string(), test_print) == true);
258 }
259 
260 TEST_CASE("early info log level")
261 {
262     PutcFixture fix;
263     const std::regex test_print("I \\([0-9]*\\) test: info", std::regex::ECMAScript);
264 
265     ESP_EARLY_LOGI(TEST_TAG, "info");
266     CHECK(regex_search(fix.get_print_buffer_string(), test_print) == true);
267 }
268 
269 TEST_CASE("early warn log level")
270 {
271     PutcFixture fix;
272     const std::regex test_print("W \\([0-9]*\\) test: warn", std::regex::ECMAScript);
273 
274     ESP_EARLY_LOGW(TEST_TAG, "warn");
275     CHECK(regex_search(fix.get_print_buffer_string(), test_print) == true);
276 }
277 
278 TEST_CASE("early error log level")
279 {
280     PutcFixture fix;
281     const std::regex test_print("E \\([0-9]*\\) test: error", std::regex::ECMAScript);
282 
283     ESP_EARLY_LOGE(TEST_TAG, "error");
284     CHECK(regex_search(fix.get_print_buffer_string(), test_print) == true);
285 }
286 
287 TEST_CASE("changing early log level")
288 {
289     PutcFixture fix(ESP_LOG_INFO);
290     const std::regex test_print("I \\([0-9]*\\) test: must indeed be printed", std::regex::ECMAScript);
291 
292     ESP_EARLY_LOGI(TEST_TAG, "must indeed be printed");
293     CHECK(regex_search(fix.get_print_buffer_string(), test_print) == true);
294 
295     fix.reset_buffer();
296     esp_log_level_set("*", ESP_LOG_WARN);
297 
298     ESP_EARLY_LOGI(TEST_TAG, "must not be printed");
299     CHECK(fix.get_print_buffer_string().size() == 0);
300 
301     fix.reset_buffer();
302     esp_log_level_set("*", ESP_LOG_INFO);
303 
304     ESP_EARLY_LOGI(TEST_TAG, "must indeed be printed");
305     CHECK(regex_search(fix.get_print_buffer_string(), test_print) == true);
306 }
307