commit e5022d756a6a884d7d380c5f945284068962c9f1
parent 3c76a4de3dc2c97ab95a46184975556c35cb8645
Author: Louis Burda <quent.burda@gmail.com>
Date: Sat, 9 Dec 2023 01:15:38 +0100
Improve logging
Diffstat:
8 files changed, 117 insertions(+), 54 deletions(-)
diff --git a/src/hid.c b/src/hid.c
@@ -139,7 +139,7 @@ active_layers_push(uint layer, uint key)
uint i;
if (active_layers_top == ARRLEN(active_layers) - 1) {
- WARN("Active stack overflow");
+ WARN(LOG_KEYMAP, "Active stack overflow");
return;
}
@@ -148,7 +148,7 @@ active_layers_push(uint layer, uint key)
active_layers[active_layers_top].key = key;
for (i = 0; i <= active_layers_top; i++) {
- DEBUG("%i. ACTIVE %u %u", i,
+ DEBUG(LOG_KEYMAP, "%i. ACTIVE %u %u", i,
active_layers[i].layer, active_layers[i].key);
}
}
@@ -177,7 +177,7 @@ void
macro_held_push(uint32_t keysym)
{
if (macro_held_cnt == MACRO_HOLD_MAX) {
- WARN("Macro held keys overflow");
+ WARN(LOG_KEYMAP, "Macro held keys overflow");
return;
}
@@ -202,7 +202,7 @@ void
add_keycode(uint8_t keycode)
{
if (keyboard_report.cnt >= 6) {
- WARN("HID report overflow");
+ WARN(LOG_HID, "HID report overflow");
return;
}
@@ -327,7 +327,7 @@ process_key(uint x, uint y, uint64_t now_us)
{
if (keymat[y][x] != keymat_prev[y][x]) {
if (bounce_mat[y][x] > now_us - 50000) {
- DEBUG("Bouncing prevented %i vs %i",
+ DEBUG(LOG_KEYMAT, "Bouncing prevented %i vs %i",
keymat[y][x], keymat_prev[y][x]);
keymat[y][x] = keymat_prev[y][x];
} else {
@@ -452,7 +452,7 @@ send_consumer_report(void)
sent = false;
if (memcmp(&consumer_report, &consumer_report_prev,
sizeof(consumer_report))) {
- INFO("CONSUMER SEND");
+ INFO(LOG_HID, "CONSUMER SEND");
tud_hid_n_report(INST_HID_MISC, REPORT_ID_CONSUMER,
&consumer_report.code, 2);
memcpy(&consumer_report_prev, &consumer_report,
diff --git a/src/keymat.c b/src/keymat.c
@@ -5,6 +5,7 @@
#include "pico/types.h"
#include "hardware/gpio.h"
#include "hardware/timer.h"
+#include "util.h"
#include <string.h>
@@ -88,3 +89,21 @@ keymat_decode_half(int side, uint32_t mask)
}
}
}
+
+void
+keymat_debug(void)
+{
+ uint x, y;
+
+ if (log_level_min > LOG_DEBUG)
+ return;
+
+ for (y = 0; y < KEY_ROWS; y++) {
+ for (x = 0; x < KEY_COLS; x++) {
+ if (!keymat_prev[y][x] && keymat[y][x])
+ DEBUG(LOG_KEYMAT, "Key pressed: %u %u", x, y);
+ else if (keymat_prev[y][x] && !keymat[y][x])
+ DEBUG(LOG_KEYMAT, "Key released: %u %u", x, y);
+ }
+ }
+}
diff --git a/src/keymat.h b/src/keymat.h
@@ -17,6 +17,8 @@ void keymat_scan(void);
uint32_t keymat_encode_half(int side);
void keymat_decode_half(int side, uint32_t);
+void keymat_debug(void);
+
extern bool keymat_prev[KEY_ROWS][KEY_COLS];
extern bool keymat[KEY_ROWS][KEY_COLS];
diff --git a/src/main.c b/src/main.c
@@ -50,7 +50,7 @@ main(void)
}
stop = board_millis();
- DEBUG("Main loop: %i ms", stop - start);
+ DEBUG(LOG_TIMING, "Main loop: %i ms", stop - start);
start = stop;
}
@@ -134,17 +134,36 @@ process_cmd(char *cmd)
arg = cmd + strlen(cmd);
}
- if (!strcmp(cmd, "log")) {
+ if (!strcmp(cmd, "log-level")) {
if (!strcmp(arg, "")) {
printf("Levels: debug, info, warn, err\n");
} else if (!strcmp(arg, "debug")) {
- loglevel = LOG_DEBUG;
+ log_level_min = LOG_DEBUG;
} else if (!strcmp(arg, "info")) {
- loglevel = LOG_INFO;
+ log_level_min = LOG_INFO;
} else if (!strcmp(arg, "warn")) {
- loglevel = LOG_WARN;
+ log_level_min = LOG_WARN;
} else {
- printf("Invalid log level\n");
+ printf("Invalid log level: %s\n", arg);
+ }
+ } else if (!strcmp(cmd, "log-groups")) {
+ log_group_mask = 0;
+ while (1) {
+ tok = strchr(arg, ',');
+ if (tok) *tok = '\0';
+ if (!strcmp(arg, "all")) {
+ log_group_mask |= LOG_ALL;
+ } else if (!strcmp(arg, "keymat")) {
+ log_group_mask |= LOG_KEYMAT;
+ } else if (!strcmp(arg, "timing")) {
+ log_group_mask |= LOG_TIMING;
+ } else if (strspn(arg, "\t ") == strlen(arg)) {
+ /* ignore */
+ } else {
+ printf("Invalid log facility: %s\n", arg);
+ }
+ if (!tok) break;
+ arg = tok + 1;
}
} else if (!strcmp(cmd, "warn")) {
if (*warnlog) {
diff --git a/src/split.c b/src/split.c
@@ -31,6 +31,8 @@
#elif SPLIT_SIDE == RIGHT
#define UART_TX_PIN 1
#define UART_RX_PIN 0
+#else
+#error "SPLIT_SIDE not set"
#endif
enum {
@@ -72,7 +74,7 @@ uart_tx_sm_init(void)
{
pio_sm_config config;
- uart_tx_sm = CLAIM_UNUSED_SM(pio0);
+ uart_tx_sm = claim_unused_sm(pio0);
uart_tx_sm_offset = pio_add_program(pio0, &uart_tx_program);
config = uart_tx_program_get_default_config(uart_tx_sm_offset);
@@ -92,7 +94,7 @@ uart_rx_sm_init(void)
{
pio_sm_config config;
- uart_rx_sm = CLAIM_UNUSED_SM(pio0);
+ uart_rx_sm = claim_unused_sm(pio0);
uart_rx_sm_offset = pio_add_program(pio0, &uart_rx_program);
config = uart_rx_program_get_default_config(uart_rx_sm_offset);
@@ -226,38 +228,38 @@ handle_cmd(uint8_t start)
return;
if (!uart_recv(&cmd, 1, false)) {
- WARN("Got start byte without command");
+ WARN(LOG_SPLIT, "Got start byte without command");
return;
}
switch (cmd) {
case CMD_SCAN_KEYMAT_REQ:
if (split_role != SLAVE) {
- WARN("Got SCAN_KEYMAT_REQ as master");
+ WARN(LOG_SPLIT, "Got SCAN_KEYMAT_REQ as master");
break;
}
scan_pending = true;
break;
case CMD_SCAN_KEYMAT_RESP:
if (split_role != MASTER) {
- WARN("Got SCAN_KEYMAT_RESP as slave");
+ WARN(LOG_SPLIT, "Got SCAN_KEYMAT_RESP as slave");
break;
}
if (uart_recv((uint8_t *) &halfmat, 4, false) != 4)
- WARN("Incomplete matrix received");
+ WARN(LOG_SPLIT, "Incomplete matrix received");
scan_pending = false;
break;
case CMD_SLAVE_WARN:
if (split_role != MASTER) {
- WARN("Got SLAVE_WARN as slave");
+ WARN(LOG_SPLIT, "Got SLAVE_WARN as slave");
break;
}
memset(msgbuf, 0, sizeof(msgbuf));
uart_recv(msgbuf, sizeof(msgbuf)-1, true);
- WARN("SLAVE: %s\n", msgbuf);
+ WARN(LOG_SPLIT, "SLAVE: %s\n", msgbuf);
break;
default:
- WARN("Unknown uart cmd: %i", cmd);
+ WARN(LOG_SPLIT, "Unknown uart cmd: %i", cmd);
break;
}
}
@@ -277,7 +279,7 @@ void
irq_rx(void)
{
if (pio_interrupt_get(pio0, 0)) {
- DEBUG("UART RX ERR");
+ DEBUG(LOG_SPLIT, "UART RX ERR");
pio_interrupt_clear(pio0, 0);
}
}
@@ -301,7 +303,7 @@ split_task(void)
if (split_role == MASTER) {
scan_pending = true;
if (!send_cmd(CMD_SCAN_KEYMAT_REQ)) {
- WARN("UART send SCAN_KEYMAT_REQ failed");
+ WARN(LOG_SPLIT, "UART send SCAN_KEYMAT_REQ failed");
return;
}
keymat_next();
@@ -313,13 +315,16 @@ split_task(void)
tud_task();
}
if (scan_pending) {
- WARN("Slave matrix scan timeout (%u)",
+ WARN(LOG_SPLIT | LOG_TIMING,
+ "Slave matrix scan timeout (%u)",
board_millis() - start_ms);
} else {
- DEBUG("Slave matrix scan success (%u)",
+ DEBUG(LOG_SPLIT | LOG_TIMING,
+ "Slave matrix scan success (%u)",
board_millis() - start_ms);
keymat_decode_half(SPLIT_OPP(SPLIT_SIDE), halfmat);
}
+ keymat_debug();
scan_pending = false;
} else {
start_ms = board_millis();
@@ -330,9 +335,10 @@ split_task(void)
}
if (scan_pending) {
keymat_scan();
- DEBUG("Sending SCAN_KEYMAT_RESP");
+ DEBUG(LOG_SPLIT, "Sending SCAN_KEYMAT_RESP");
if (!send_cmd(CMD_SCAN_KEYMAT_RESP)) {
- WARN("UART send SCAN_KEYMAT_RESP failed");
+ WARN(LOG_SPLIT,
+ "UART send SCAN_KEYMAT_RESP failed");
return;
}
halfmat = keymat_encode_half(SPLIT_SIDE);
@@ -348,11 +354,11 @@ split_warn_master(const char *msg)
uint32_t len;
if (!send_cmd(CMD_SLAVE_WARN)) {
- WARN("UART send SLAVE_WARN failed");
+ WARN(LOG_SPLIT, "UART send SLAVE_WARN failed");
return;
}
len = strlen(msg) + 1;
if (uart_send((const uint8_t *) msg, len) != len)
- WARN("UART send warning failed");
+ WARN(LOG_SPLIT, "UART send warning failed");
}
diff --git a/src/util.c b/src/util.c
@@ -14,7 +14,8 @@
#include <stdio.h>
char warnlog[256];
-int loglevel = LOG_INFO;
+int log_level_min = LOG_INFO;
+int log_group_mask = LOG_ALL;
static void
__attribute__((format(printf, 1, 0)))
@@ -40,11 +41,17 @@ panic_task(const char *fmtstr, va_list ap, uint32_t sleep_ms)
}
void
-__attribute__ ((format (printf, 2, 3)))
-stdio_log(int level, const char *fmtstr, ...)
+__attribute__ ((format (printf, 3, 4)))
+stdio_log(int facility, int level, const char *fmtstr, ...)
{
va_list ap, cpy;
+ if (!(facility & log_group_mask))
+ return;
+
+ if (level < log_level_min)
+ return;
+
if (level == LOG_WARN) {
led_start_blip(HARD_RED, 100);
va_copy(cpy, ap);
@@ -56,9 +63,6 @@ stdio_log(int level, const char *fmtstr, ...)
split_warn_master(warnlog);
}
- if (level > loglevel)
- return;
-
if (!tud_cdc_connected())
return;
diff --git a/src/util.h b/src/util.h
@@ -6,12 +6,13 @@
#include <stdbool.h>
#include <stdint.h>
#include <stdarg.h>
+#include <sys/types.h>
#define ARRLEN(x) (sizeof(x) / sizeof((x)[0]))
-#define WARN(...) stdio_log(LOG_WARN, "WARN : " __VA_ARGS__)
-#define INFO(...) stdio_log(LOG_INFO, "INFO : " __VA_ARGS__)
-#define DEBUG(...) stdio_log(LOG_DEBUG, "DEBUG: " __VA_ARGS__)
+#define WARN(group, ...) stdio_log(group, LOG_WARN, "WARN : " __VA_ARGS__)
+#define INFO(group, ...) stdio_log(group, LOG_INFO, "INFO : " __VA_ARGS__)
+#define DEBUG(group, ...) stdio_log(group, LOG_DEBUG, "DEBUG: " __VA_ARGS__)
#define PANIC(...) blink_panic(200, HARD_RED, __VA_ARGS__);
#define ASSERT(cond) do { \
@@ -19,21 +20,35 @@
#cond, __FILE__, __LINE__); \
} while (0)
-#define CLAIM_UNUSED_SM(pio) ({ \
- int tmp = pio_claim_unused_sm(pio, false); \
- ASSERT(tmp >= 0); \
- (uint) tmp; })
-
enum {
- LOG_NONE,
- LOG_WARN,
+ LOG_DEBUG,
LOG_INFO,
- LOG_DEBUG
+ LOG_WARN
};
-void stdio_log(int loglevel, const char *fmtstr, ...);
+enum {
+ LOG_NONE = 0b000000,
+ LOG_MISC = 0b000001,
+ LOG_KEYMAT = 0b000010,
+ LOG_KEYMAP = 0b000100,
+ LOG_HID = 0b001000,
+ LOG_TIMING = 0b010000,
+ LOG_SPLIT = 0b100000,
+ LOG_ALL = 0b111111,
+};
+
+void stdio_log(int group, int level, const char *fmtstr, ...);
void blink_panic(uint32_t blink_ms, uint32_t rgb, const char *fmtstr, ...);
+static inline uint
+claim_unused_sm(PIO pio)
+{
+ int tmp = pio_claim_unused_sm(pio, false);
+ ASSERT(tmp >= 0);
+ return (uint) tmp;
+}
+
extern char warnlog[];
-extern int loglevel;
+extern int log_level_min;
+extern int log_group_mask;
diff --git a/src/ws2812.c b/src/ws2812.c
@@ -12,16 +12,14 @@ ws2812_init(struct ws2812 *pix, PIO pio, uint pin)
{
pio_sm_config config;
uint offset;
- uint sm;
pix->pio = pio;
pix->pin = pin;
- sm = CLAIM_UNUSED_SM(pio);
- pix->sm = sm;
+ pix->sm = claim_unused_sm(pio);
pio_gpio_init(pio, pin);
- pio_sm_set_consecutive_pindirs(pio, sm, pin, 1, true);
+ pio_sm_set_consecutive_pindirs(pio, pix->sm, pin, 1, true);
offset = pio_add_program(pix->pio, &ws2812_program);
config = ws2812_program_get_default_config(offset);
@@ -31,8 +29,8 @@ ws2812_init(struct ws2812 *pix, PIO pio, uint pin)
sm_config_set_clkdiv(&config,
(float) clock_get_hz(clk_sys) / (800000 * CYCLES_PER_BIT));
- pio_sm_init(pio, sm, offset, &config);
- pio_sm_set_enabled(pio, sm, true);
+ pio_sm_init(pio, pix->sm, offset, &config);
+ pio_sm_set_enabled(pio, pix->sm, true);
pix->init = true;
}
