Skip to content

Commit 4a55d76

Browse files
committed
Add sparse ISR-compatible logging.
Fix syntax error. Bump minor.
1 parent 12fd1cf commit 4a55d76

8 files changed

Lines changed: 353 additions & 21 deletions

File tree

components/robusto/base/src/logging/logging_esp-idf.c

Lines changed: 283 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -36,6 +36,283 @@
3636

3737
#include <esp_log.h>
3838
#include <esp_debug_helpers.h>
39+
#include <stdio.h>
40+
#include "freertos/FreeRTOS.h"
41+
#include "freertos/queue.h"
42+
#include "freertos/task.h"
43+
#include "freertos/portmacro.h"
44+
45+
// Optional ROM printf for drain output; disabled by default to avoid UART in ISR storms.
46+
int esp_rom_printf(const char *fmt, ...);
47+
48+
#ifndef ROB_LOG_ISR_OUTPUT
49+
#define ROB_LOG_ISR_OUTPUT 0
50+
#endif
51+
52+
// Minimal, ISR-friendly formatter that supports %s, %d, %u, %x, %02x, and %%.
53+
static size_t isr_write_uint(char *dst, size_t cap, unsigned int value, int base, bool lower, int min_width, bool zero_pad)
54+
{
55+
char tmp[16];
56+
const char *digits = lower ? "0123456789abcdef" : "0123456789ABCDEF";
57+
int i = 0;
58+
if (value == 0)
59+
{
60+
tmp[i++] = '0';
61+
}
62+
else
63+
{
64+
while (value && i < (int)sizeof(tmp))
65+
{
66+
tmp[i++] = digits[value % base];
67+
value /= base;
68+
}
69+
}
70+
71+
while (i < min_width && i < (int)sizeof(tmp))
72+
{
73+
tmp[i++] = zero_pad ? '0' : ' ';
74+
}
75+
76+
size_t written = 0;
77+
while (i > 0 && written + 1 < cap)
78+
{
79+
dst[written++] = tmp[--i];
80+
}
81+
return written;
82+
}
83+
84+
static size_t isr_vsnprintf(char *out, size_t size, const char *fmt, va_list ap)
85+
{
86+
size_t written = 0;
87+
if (size == 0)
88+
{
89+
return 0;
90+
}
91+
92+
for (const char *p = fmt; *p && written + 1 < size; ++p)
93+
{
94+
if (*p != '%')
95+
{
96+
out[written++] = *p;
97+
continue;
98+
}
99+
100+
++p;
101+
if (*p == 0)
102+
{
103+
break;
104+
}
105+
if (*p == '%')
106+
{
107+
out[written++] = '%';
108+
continue;
109+
}
110+
111+
bool zero_pad = false;
112+
int min_width = 0;
113+
if (*p == '0')
114+
{
115+
zero_pad = true;
116+
++p;
117+
if (*p >= '0' && *p <= '9')
118+
{
119+
min_width = *p - '0';
120+
++p;
121+
}
122+
}
123+
124+
switch (*p)
125+
{
126+
case 's':
127+
{
128+
const char *s = va_arg(ap, const char *);
129+
if (s == NULL)
130+
{
131+
s = "(null)";
132+
}
133+
while (*s && written + 1 < size)
134+
{
135+
out[written++] = *s++;
136+
}
137+
break;
138+
}
139+
case 'd':
140+
{
141+
int v = va_arg(ap, int);
142+
if (v < 0 && written + 1 < size)
143+
{
144+
out[written++] = '-';
145+
v = -v;
146+
}
147+
written += isr_write_uint(out + written, size - written, (unsigned int)v, 10, true, min_width, zero_pad);
148+
break;
149+
}
150+
case 'u':
151+
written += isr_write_uint(out + written, size - written, va_arg(ap, unsigned int), 10, true, min_width, zero_pad);
152+
break;
153+
case 'x':
154+
case 'X':
155+
written += isr_write_uint(out + written, size - written, va_arg(ap, unsigned int), 16, (*p == 'x'), min_width, zero_pad);
156+
break;
157+
default:
158+
// Unknown specifier: emit it verbatim.
159+
if (written + 1 < size)
160+
{
161+
out[written++] = '%';
162+
}
163+
if (written + 1 < size)
164+
{
165+
out[written++] = *p;
166+
}
167+
break;
168+
}
169+
}
170+
171+
out[written] = '\0';
172+
return written;
173+
}
174+
175+
#ifndef ROB_LOG_ISR_QUEUE_LEN
176+
#define ROB_LOG_ISR_QUEUE_LEN 16
177+
#endif
178+
179+
#ifndef ROB_LOG_ISR_MAX_MESSAGE
180+
#define ROB_LOG_ISR_MAX_MESSAGE 128
181+
#endif
182+
183+
#ifndef ROB_LOG_ISR_TASK_STACK_WORDS
184+
#define ROB_LOG_ISR_TASK_STACK_WORDS (configMINIMAL_STACK_SIZE * 3)
185+
#endif
186+
187+
#ifndef ROB_LOG_ISR_TASK_PRIORITY
188+
#define ROB_LOG_ISR_TASK_PRIORITY (tskIDLE_PRIORITY + 1)
189+
#endif
190+
191+
typedef struct
192+
{
193+
rob_log_level_t level;
194+
const char *tag;
195+
char message[ROB_LOG_ISR_MAX_MESSAGE];
196+
} rob_log_isr_msg_t;
197+
198+
static StaticQueue_t rob_log_isr_queue_struct;
199+
static uint8_t rob_log_isr_queue_storage[ROB_LOG_ISR_QUEUE_LEN * sizeof(rob_log_isr_msg_t)];
200+
static QueueHandle_t rob_log_isr_queue;
201+
202+
static StaticTask_t rob_log_isr_task_tcb;
203+
static StackType_t rob_log_isr_task_stack[ROB_LOG_ISR_TASK_STACK_WORDS];
204+
static TaskHandle_t rob_log_isr_task_handle;
205+
206+
static void rob_log_isr_drain_task(void *arg)
207+
{
208+
(void)arg;
209+
rob_log_isr_msg_t msg;
210+
while (true)
211+
{
212+
if (xQueueReceive(rob_log_isr_queue, &msg, portMAX_DELAY) == pdTRUE)
213+
{
214+
#if ROB_LOG_ISR_OUTPUT
215+
esp_rom_printf("ISR[%s]: %s\n", msg.tag ? msg.tag : "?", msg.message);
216+
#else
217+
(void)msg; // Drop silently to avoid UART work.
218+
#endif
219+
}
220+
}
221+
}
222+
223+
void rob_log_isr_init(void)
224+
{
225+
if (rob_log_isr_queue != NULL)
226+
{
227+
return;
228+
}
229+
230+
rob_log_isr_queue = xQueueCreateStatic(ROB_LOG_ISR_QUEUE_LEN,
231+
sizeof(rob_log_isr_msg_t),
232+
rob_log_isr_queue_storage,
233+
&rob_log_isr_queue_struct);
234+
if (rob_log_isr_queue == NULL)
235+
{
236+
return;
237+
}
238+
239+
rob_log_isr_task_handle = xTaskCreateStatic(rob_log_isr_drain_task,
240+
"rob_log_isr",
241+
ROB_LOG_ISR_TASK_STACK_WORDS,
242+
NULL,
243+
ROB_LOG_ISR_TASK_PRIORITY,
244+
rob_log_isr_task_stack,
245+
&rob_log_isr_task_tcb);
246+
(void)rob_log_isr_task_handle;
247+
}
248+
249+
bool rob_log_isr_enqueue(rob_log_level_t level, const char *tag, const char *format, ...)
250+
{
251+
if (rob_log_isr_queue == NULL)
252+
{
253+
if (!xPortInIsrContext())
254+
{
255+
rob_log_isr_init();
256+
}
257+
if (rob_log_isr_queue == NULL)
258+
{
259+
return false;
260+
}
261+
}
262+
263+
const bool in_isr = xPortInIsrContext();
264+
// If ISR logging is globally disabled, drop immediately.
265+
// This is a hard kill-switch to ensure no ISR-side enqueues if UART/RTOS contention persists.
266+
if (in_isr && ROB_LOG_ISR_OUTPUT == 0)
267+
{
268+
return false;
269+
}
270+
if (in_isr)
271+
{
272+
if (xQueueIsQueueFullFromISR(rob_log_isr_queue))
273+
{
274+
return false;
275+
}
276+
}
277+
else if (uxQueueSpacesAvailable(rob_log_isr_queue) == 0)
278+
{
279+
return false;
280+
}
281+
282+
rob_log_isr_msg_t msg = {
283+
.level = level,
284+
.tag = tag,
285+
};
286+
287+
va_list list;
288+
va_start(list, format);
289+
if (in_isr)
290+
{
291+
isr_vsnprintf(msg.message, ROB_LOG_ISR_MAX_MESSAGE, format, list);
292+
}
293+
else
294+
{
295+
vsnprintf(msg.message, ROB_LOG_ISR_MAX_MESSAGE, format, list);
296+
}
297+
va_end(list);
298+
299+
BaseType_t higher_priority_task_woken = pdFALSE;
300+
BaseType_t result;
301+
if (in_isr)
302+
{
303+
result = xQueueSendFromISR(rob_log_isr_queue, &msg, &higher_priority_task_woken);
304+
if (higher_priority_task_woken == pdTRUE)
305+
{
306+
portYIELD_FROM_ISR();
307+
}
308+
}
309+
else
310+
{
311+
result = xQueueSend(rob_log_isr_queue, &msg, 0);
312+
}
313+
314+
return result == pdPASS;
315+
}
39316

40317
// Print a stack trace using esp_backtrace_print() in esp_debug_helpers.h
41318
void compat_rob_log_stack_trace(int levels)
@@ -54,5 +331,10 @@ void compat_rob_log_write_sparse(const char *tag, const char *format)
54331
compat_rob_log_writev(ROB_LOG_LOCAL_LEVEL, tag, format, arg_list);
55332
}
56333
#endif
57-
void r_init_logging(){};
334+
void r_init_logging()
335+
{
336+
#if ROB_LOG_LOCAL_LEVEL > ROB_LOG_NONE
337+
rob_log_isr_init();
338+
#endif
339+
}
58340
#endif

components/robusto/idf_component.yml

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1,4 +1,4 @@
1-
version: "2.1.20"
1+
version: "2.2.0"
22
description: "Robusto framework"
33
url: "https://github.com/RobustoFramework"
44
repository: "https://github.com/RobustoFramework/Robusto.git"

components/robusto/include/robusto_logging.h

Lines changed: 33 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -37,6 +37,7 @@
3737

3838

3939
#include <stdint.h>
40+
#include <stdbool.h>
4041

4142
#define ROB_LOG_LOCAL_LEVEL CONFIG_ROB_LOG_MAXIMUM_LEVEL
4243

@@ -72,6 +73,19 @@ typedef enum
7273
void rob_log_write(rob_log_level_t level, const char *tag, const char *format, ...) __attribute__((format(printf, 3, 4)));
7374
void compat_rob_log_writev(rob_log_level_t level, const char* tag, const char* format, va_list args);
7475
void compat_rob_log_stack_trace(int levels);
76+
#ifdef USE_ESPIDF
77+
bool rob_log_isr_enqueue(rob_log_level_t level, const char *tag, const char *format, ...) __attribute__((format(printf, 3, 4)));
78+
void rob_log_isr_init(void);
79+
#else
80+
static inline bool rob_log_isr_enqueue(rob_log_level_t level, const char *tag, const char *format, ...)
81+
{
82+
(void)level;
83+
(void)tag;
84+
(void)format;
85+
return false;
86+
}
87+
static inline void rob_log_isr_init(void) {}
88+
#endif
7589

7690
void r_init_logging();
7791

@@ -155,21 +169,37 @@ void r_init_logging();
155169
#define ROB_LOGI_STAY(tag, format, ...) rob_log_write(ROB_LOG_INFO, tag, ROB_LOG_FORMAT_NO_NL(I, format), ROB_LOG_TIME_SRC, tag, ##__VA_ARGS__)
156170
// Print a stack trace of the current call stack
157171
#define ROB_LOG_STACK_TRACE(levels) compat_rob_log_stack_trace(levels)
158-
#else // ROB_LOG_LOCAL_LEVEL > ROB_LOG_NONE
172+
173+
#define ROB_LOGE_ISR(tag, format, ...) rob_log_isr_enqueue(ROB_LOG_ERROR, tag, format, ##__VA_ARGS__)
174+
#define ROB_LOGW_ISR(tag, format, ...) rob_log_isr_enqueue(ROB_LOG_WARN, tag, format, ##__VA_ARGS__)
175+
#define ROB_LOGI_ISR(tag, format, ...) rob_log_isr_enqueue(ROB_LOG_INFO, tag, format, ##__VA_ARGS__)
176+
#define ROB_LOGD_ISR(tag, format, ...) rob_log_isr_enqueue(ROB_LOG_DEBUG, tag, format, ##__VA_ARGS__)
177+
#define ROB_LOGV_ISR(tag, format, ...) rob_log_isr_enqueue(ROB_LOG_VERBOSE, tag, format, ##__VA_ARGS__)
178+
#else
159179
#define ROB_LOGE(tag, format, ...) do {} while (0)
160180
#define ROB_LOGW(tag, format, ...) do {} while (0)
161181
#define ROB_LOGI(tag, format, ...) do {} while (0)
162182
#define ROB_LOGD(tag, format, ...) do {} while (0)
163183
#define ROB_LOGV(tag, format, ...) do {} while (0)
164184
#define ROB_LOG_STACK_TRACE(levels) do {} while (0)
165-
#define ROB_LOG_LEVEL(level, tag, format, ...) do {} while (0)
166-
#define ROB_LOGI_STAY(tag, format, ...) do {} while (0)
185+
#define rob_log_isr_enqueue(level, tag, format, ...) (false)
186+
#define rob_log_isr_init() do {} while (0)
187+
#define ROB_LOGE_ISR(tag, format, ...) do {} while (0)
188+
#define ROB_LOGW_ISR(tag, format, ...) do {} while (0)
189+
#define ROB_LOGI_ISR(tag, format, ...) do {} while (0)
190+
#define ROB_LOGD_ISR(tag, format, ...) do {} while (0)
191+
#define ROB_LOGV_ISR(tag, format, ...) do {} while (0)
167192
#endif // ROB_LOG_LOCAL_LEVEL > ROB_LOG_NONE
168193

194+
195+
196+
169197
void rob_log_bit_mesh(rob_log_level_t level,
170198
const char *tag,
171199
uint8_t * data, int data_len);
172200

201+
202+
173203
#ifdef __cplusplus
174204
} /* extern "C" */
175205
#endif

components/robusto/include/robusto_peer.h

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -173,6 +173,10 @@ extern "C"
173173
* @return robusto_peer_t* The matching peer
174174
*/
175175
robusto_peer_t *robusto_peers_find_peer_by_base_mac_address(rob_mac_address *mac_address);
176+
/**
177+
* @brief Find peer by MAC without emitting any logs (ISR-safe helper)
178+
*/
179+
robusto_peer_t *robusto_peers_find_peer_by_base_mac_address_silent(rob_mac_address *mac_address);
176180

177181
#ifdef CONFIG_ROBUSTO_SUPPORTS_I2C
178182
/**

0 commit comments

Comments
 (0)