refactor(core): use LOG macros instead of printfs
What changed, and why it matters
This commit is a straightforward code cleanup: it replaces old-style printf debug messages with a new centralized logging system (LOG_ macros). It also removes some unused non-production debug hooks and switches header include guards to '#pragma once'. There is no change to security logic, cryptography, user-facing behavior, or access controls.
No security action required. Treat as normal refactoring; standard regression testing for emulator/unix builds is sufficient.
Security signals we found
No strong security signals were identified.
Evidence from the diff
The diff refactors debug output across 16 files in Trezor’s embedded firmware. printf/dbg_printf calls are replaced by LOG_ERR/LOG_WARN/LOG_INF/LOG_DBG/LOG_HEXDUMP_DBG macros from
Changed components
core/embed/io/ble/unix/ble.ccore/embed/io/display/unix/display_driver.ccore/embed/io/touch/ft3168/ft3168.ccore/embed/io/touch/ft6x36/ft6x36.ccore/embed/io/touch/touch_poll.ccore/embed/projects/bootloader/emulator.ccore/embed/projects/firmware/main.ccore/embed/sec/optiga/inc/sec/optiga.hcore/embed/sec/optiga/inc/sec/optiga_commands.hcore/embed/sec/optiga/inc/sec/optiga_common.hcore/embed/sec/optiga/inc/sec/optiga_transport.hcore/embed/sec/optiga/optiga_commands.ccore/embed/sec/optiga/optiga_init.ccore/embed/sec/optiga/optiga_transport.ccore/embed/sys/dbg/inc/sys/syslog_config.hcore/embed/sys/startup/unix/bootutils.cInspect captured patch +166 / −175
diff --git a/core/embed/io/ble/unix/ble.c b/core/embed/io/ble/unix/ble.c
index 37dad1ad..371f4cf9 100644
--- a/core/embed/io/ble/unix/ble.c
+++ b/core/embed/io/ble/unix/ble.c
@@ -1,7 +1,28 @@
+/*
+ * This file is part of the Trezor project, https://trezor.io/
+ *
+ * Copyright (c) SatoshiLabs
+ *
+ * This program is free software: you can redistribute it and/or modify
+ * it under the terms of the GNU General Public License as published by
+ * the Free Software Foundation, either version 3 of the License, or
+ * (at your option) any later version.
+ *
+ * This program is distributed in the hope that it will be useful,
+ * but WITHOUT ANY WARRANTY; without even the implied warranty of
+ * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
+ * GNU General Public License for more details.
+ *
+ * You should have received a copy of the GNU General Public License
+ * along with this program. If not, see <http://www.gnu.org/licenses/>.
+ */
+
+#include <trezor_rtl.h>
+
#include <io/ble.h>
#include <io/unix/sock.h>
+#include <rtl/logging.h>
#include <sys/sysevent_source.h>
-#include <trezor_rtl.h>
#include <arpa/inet.h>
#include <stdlib.h>
@@ -10,6 +31,8 @@
#include <time.h>
#include <unistd.h>
+LOG_DECLARE(ble_driver)
+
static const uint16_t DATA_PORT_OFFSET = 4; // see usb_config.c
static const uint16_t EVENT_PORT_OFFSET = 5;
@@ -111,7 +134,7 @@ bool ble_init(void) {
cleanup:
memset(drv, 0, sizeof(ble_driver_t));
- printf("unix/ble: init failed\n");
+ LOG_ERR("init failed");
return false;
}
@@ -156,7 +179,7 @@ static bool send_to_emu(char cmdtype) {
ssize_t r = sock_sendto(&drv->event_sock, &command, sizeof(command));
if (r != sizeof(command)) {
- printf("unix/ble: failed to write command %c: %zd\n", cmdtype, r);
+ LOG_ERR("failed to write command %c: %zd", cmdtype, r);
}
return true;
@@ -210,7 +233,7 @@ bool ble_erase_bonds(void) {
if (!drv->initialized) {
return false;
}
- printf("unix/ble: erase bonds\n");
+ LOG_INF("erase bonds");
memset(drv->bonds, 0, sizeof(drv->bonds));
drv->bonds_len = 0;
drv->connected = false;
@@ -260,7 +283,7 @@ bool ble_get_event(ble_event_t *event) {
if (r <= 0) {
return false;
} else if (r > sizeof(ble_event_t)) {
- printf("unix/ble: event packet too long: %zd\n", r);
+ LOG_ERR("event packet too long: %zd", r);
return false;
}
@@ -300,14 +323,14 @@ bool ble_get_event(ble_event_t *event) {
send_to_emu(' ');
break;
case BLE_CONNECTION_CHANGED:
- printf("unix/ble: CONNECTION_CHANGED not implemented\n");
+ LOG_WARN("CONNECTION_CHANGED not implemented");
break;
case BLE_EMULATOR_PING:
send_to_emu(' ');
return ble_get_event(event); // do not forward to app
break;
default:
- printf("unix/ble: unknown event type\n");
+ LOG_WARN("unknown event type");
break;
}
@@ -373,7 +396,7 @@ bool ble_write(const uint8_t *data, uint16_t len) {
}
if (!drv->connected) {
- printf("unix/ble: ble_write while disconnected\n");
+ LOG_ERR("ble_write while disconnected");
return false;
}
@@ -397,7 +420,7 @@ uint32_t ble_read(uint8_t *data, uint16_t max_len) {
}
if (!drv->connected) {
- printf("unix/ble: ble_read while disconnected\n");
+ LOG_ERR("ble_read while disconnected");
return false;
}
@@ -419,7 +442,7 @@ bool ble_get_mac(bt_le_addr_t *addr) {
return false;
}
- printf("unix/ble: ble_get_mac not implemented\n");
+ LOG_WARN("ble_get_mac not implemented");
for (size_t i = 0; i < sizeof(addr->addr); i++) {
addr->addr[i] = i + 0xe1;
}
@@ -437,7 +460,7 @@ uint8_t ble_get_bond_list(bt_le_addr_t *bonds, size_t count) {
}
void ble_set_high_speed(bool enable) {
- printf("unix/ble: set_high_speed not implemented\n");
+ LOG_WARN("set_high_speed not implemented");
}
bool ble_unpair(const bt_le_addr_t *addr) {
@@ -452,7 +475,7 @@ bool ble_unpair(const bt_le_addr_t *addr) {
}
void ble_notify(const uint8_t *data, size_t len) {
- printf("unix/ble: ble_notify not implemented\n");
+ LOG_WARN("ble_notify not implemented");
}
void ble_set_enabled(bool enabled) {
diff --git a/core/embed/io/display/unix/display_driver.c b/core/embed/io/display/unix/display_driver.c
index 677afaad..809f4e8e 100644
--- a/core/embed/io/display/unix/display_driver.c
+++ b/core/embed/io/display/unix/display_driver.c
@@ -29,6 +29,7 @@
#include <io/display.h>
#include <io/unix/sdl_display.h>
+#include <rtl/logging.h>
#include <SDL.h>
#include <SDL_image.h>
@@ -39,6 +40,8 @@
#include "suspend_overlay.h"
#endif
+LOG_DECLARE(display_driver)
+
#define EMULATOR_BORDER 16
#ifdef UI_COLOR_32BIT
@@ -110,7 +113,7 @@ bool display_init(display_content_mode_t mode) {
}
if (SDL_Init(SDL_INIT_VIDEO) != 0) {
- printf("%s\n", SDL_GetError());
+ LOG_ERR("%s", SDL_GetError());
error_shutdown("SDL_Init error");
}
atexit(display_exit_handler);
@@ -135,12 +138,12 @@ bool display_init(display_content_mode_t mode) {
);
free(window_title_alloc);
if (!drv->window) {
- printf("%s\n", SDL_GetError());
+ LOG_ERR("%s", SDL_GetError());
error_shutdown("SDL_CreateWindow error");
}
drv->renderer = SDL_CreateRenderer(drv->window, -1, SDL_RENDERER_SOFTWARE);
if (!drv->renderer) {
- printf("%s\n", SDL_GetError());
+ LOG_ERR("%s", SDL_GetError());
SDL_DestroyWindow(drv->window);
error_shutdown("SDL_CreateRenderer error");
}
diff --git a/core/embed/io/touch/ft3168/ft3168.c b/core/embed/io/touch/ft3168/ft3168.c
index 3129363a..dcb067dc 100644
--- a/core/embed/io/touch/ft3168/ft3168.c
+++ b/core/embed/io/touch/ft3168/ft3168.c
@@ -24,6 +24,7 @@
#include <io/i2c_bus.h>
#include <io/touch.h>
+#include <rtl/logging.h>
#include <sys/systick.h>
#include "ft3168.h"
@@ -33,6 +34,8 @@
#include "../touch_poll.h"
+LOG_DECLARE(touch_driver)
+
// #define TOUCH_TRACE_REGS
typedef struct {
@@ -433,8 +436,8 @@ void trace_regs(uint8_t* regs) {
uint32_t time = systicks_ms() % 10000;
- printf("%04ld [gesture=%02X, nb_touches=%d, flags=%c, x=%3d, y=%3d]\r\n",
- time, gesture, nb_touches, event, x, y);
+ LOG_DBG("%04ld [gesture=%02X, nb_touches=%d, flags=%c, x=%3d, y=%3d]\r\n",
+ time, gesture, nb_touches, event, x, y);
}
#endif
diff --git a/core/embed/io/touch/ft6x36/ft6x36.c b/core/embed/io/touch/ft6x36/ft6x36.c
index f7b86c92..d44df2b5 100644
--- a/core/embed/io/touch/ft6x36/ft6x36.c
+++ b/core/embed/io/touch/ft6x36/ft6x36.c
@@ -24,6 +24,7 @@
#include <io/i2c_bus.h>
#include <io/touch.h>
+#include <rtl/logging.h>
#include <sys/systick.h>
#include "ft6x36.h"
@@ -35,6 +36,8 @@
#include "../touch_poll.h"
+LOG_DECLARE(touch_driver)
+
// #define TOUCH_TRACE_REGS
typedef struct {
@@ -413,8 +416,8 @@ void trace_regs(uint8_t* regs) {
uint32_t time = systicks_ms() % 10000;
- printf("%04ld [gesture=%02X, nb_touches=%d, flags=%c, x=%3d, y=%3d]\r\n",
- time, gesture, nb_touches, event, x, y);
+ LOG_DBG("%04ld [gesture=%02X, nb_touches=%d, flags=%c, x=%3d, y=%3d]\r\n",
+ time, gesture, nb_touches, event, x, y);
}
#endif
diff --git a/core/embed/io/touch/touch_poll.c b/core/embed/io/touch/touch_poll.c
index 0ebcc7a9..528edce1 100644
--- a/core/embed/io/touch/touch_poll.c
+++ b/core/embed/io/touch/touch_poll.c
@@ -22,13 +22,14 @@
#include <trezor_rtl.h>
#include <io/touch.h>
+#include <rtl/logging.h>
#include <sys/sysevent_source.h>
#include <sys/systask.h>
#include <sys/systick.h>
#include "touch_poll.h"
-// #define TOUCH_TRACE_EVENT
+LOG_DECLARE(touch_driver);
typedef struct {
// Time (in ticks) when the tls was last updated
@@ -65,25 +66,6 @@ bool touch_fsm_event_ready(touch_fsm_t* fsm, uint32_t touch_state) {
return fsm->state != touch_state;
}
-#ifdef TOUCH_TRACE_EVENT
-void trace_event(uint32_t event) {
- char event_type = (event & TOUCH_START) ? 'D'
- : (event & TOUCH_MOVE) ? 'M'
- : (event & TOUCH_END) ? 'U'
- : '-';
-
- uint16_t x = touch_unpack_x(event);
- uint16_t y = touch_unpack_y(event);
-
- uint32_t time = hal_ticks_ms() % 10000;
-
- systask_id_t task_id = systask_id(systask_active());
-
- dbg_printf("%d [task=%d, event=%c, x=%d, y=%d]\r\n", time, task_id,
- event_type, x, y);
-}
-#endif
-
uint32_t touch_fsm_get_event(touch_fsm_t* fsm, uint32_t touch_state) {
uint32_t ticks = hal_ticks_ms();
@@ -164,6 +146,13 @@ uint32_t touch_fsm_get_event(touch_fsm_t* fsm, uint32_t touch_state) {
return event;
}
+static inline char event_type_char(uint32_t event) {
+ return (event & TOUCH_START) ? 'D'
+ : (event & TOUCH_MOVE) ? 'M'
+ : (event & TOUCH_END) ? 'U'
+ : '-';
+}
+
uint32_t touch_get_event(void) {
touch_fsm_t* fsm = &g_touch_tls[systask_id(systask_active())];
@@ -171,11 +160,10 @@ uint32_t touch_get_event(void) {
uint32_t event = touch_fsm_get_event(fsm, touch_state);
-#ifdef TOUCH_TRACE_EVENT
if (event != 0) {
- trace_event(event);
+ LOG_DBG("touch_event: ev=%c, x=%d, y=%d", event_type_char(event),
+ touch_unpack_x(event), touch_unpack_y(event));
}
-#endif
return event;
}
diff --git a/core/embed/projects/bootloader/emulator.c b/core/embed/projects/bootloader/emulator.c
index d8c6e9d3..ba6252fa 100644
--- a/core/embed/projects/bootloader/emulator.c
+++ b/core/embed/projects/bootloader/emulator.c
@@ -6,6 +6,7 @@
#include <SDL.h>
#include <io/display.h>
+#include <rtl/logging.h>
#include <sys/bootargs.h>
#include <sys/bootutils.h>
#include <util/flash.h>
@@ -19,6 +20,8 @@
#include "emulator.h"
#include "rust_ui_common.h"
+LOG_DECLARE(emulator)
+
#undef FIRMWARE_START
uint8_t *FIRMWARE_START = 0;
@@ -234,11 +237,11 @@ void jump_to_next_stage(uint32_t address) {
storage_empty(&STORAGE_AREAS[0]) && storage_empty(&STORAGE_AREAS[1]);
if (storage_is_erased) {
- printf("STORAGE WAS ERASED\n");
+ LOG_WARN("Storage was erased");
error_shutdown_ex("BOOTLOADER EXIT", "Jumped to firmware",
"STORAGE WAS ERASED");
} else {
- printf("storage was retained\n");
+ LOG_WARN("Storage was retained");
error_shutdown_ex("BOOTLOADER EXIT", "Jumped to firmware",
"STORAGE WAS RETAINED");
}
diff --git a/core/embed/projects/firmware/main.c b/core/embed/projects/firmware/main.c
index 32765ff7..dd1ad922 100644
--- a/core/embed/projects/firmware/main.c
+++ b/core/embed/projects/firmware/main.c
@@ -34,6 +34,7 @@
#include "ports/stm32/pendsv.h"
#include <io/display.h>
+#include <rtl/logging.h>
#include <sys/linker_utils.h>
#include <sys/notify.h>
#include <sys/systask.h>
@@ -63,6 +64,8 @@ extern const void nrf_app_size;
#endif
+LOG_DECLARE(coreapp_main)
+
int main_func(uint32_t cmd, void *arg) {
if (cmd == 1) {
systask_postmortem_t *info = (systask_postmortem_t *)arg;
@@ -125,7 +128,7 @@ int main_func(uint32_t cmd, void *arg) {
ensure(sectrue * (zkp_context_init() == 0), NULL);
#endif
- printf("CORE: Preparing stack\n");
+ LOG_INF("Preparing stack");
// Stack limit should be less than real stack size, so we have a chance
// to recover from limit hit.
mp_stack_set_top(&_stack_section_end);
@@ -138,22 +141,22 @@ int main_func(uint32_t cmd, void *arg) {
#endif
// GC init
- printf("CORE: Starting GC\n");
+ LOG_INF("Starting GC");
gc_init(&_heap_start, &_heap_end);
// Interpreter init
- printf("CORE: Starting interpreter\n");
+ LOG_INF("Starting interpreter");
mp_init();
mp_obj_list_init(mp_sys_argv, 0);
mp_obj_list_init(mp_sys_path, 0);
mp_obj_list_append(mp_sys_path, MP_OBJ_NEW_QSTR(MP_QSTR__dot_frozen));
// Execute the main script
- printf("CORE: Executing main script\n");
+ LOG_INF("Executing main script");
pyexec_frozen_module("main.py");
// Clean up
- printf("CORE: Main script finished, cleaning up\n");
+ LOG_INF("Main script finished, cleaning up");
mp_deinit();
// Python code shouldn't ever exit, avoid black screen if it does
diff --git a/core/embed/sec/optiga/inc/sec/optiga.h b/core/embed/sec/optiga/inc/sec/optiga.h
index a293cd8c..1356ecf1 100644
--- a/core/embed/sec/optiga/inc/sec/optiga.h
+++ b/core/embed/sec/optiga/inc/sec/optiga.h
@@ -17,8 +17,7 @@
* along with this program. If not, see <http://www.gnu.org/licenses/>.
*/
-#ifndef TREZORHAL_OPTIGA_H
-#define TREZORHAL_OPTIGA_H
+#pragma once
#include <trezor_types.h>
@@ -110,5 +109,3 @@ bool __wur optiga_pin_get_rem(uint32_t *ctr);
bool __wur optiga_pin_decrease_rem_v4(uint32_t count);
bool __wur optiga_pin_decrease_rem(uint32_t count);
-
-#endif
diff --git a/core/embed/sec/optiga/inc/sec/optiga_commands.h b/core/embed/sec/optiga/inc/sec/optiga_commands.h
index da13cede..1a73e852 100644
--- a/core/embed/sec/optiga/inc/sec/optiga_commands.h
+++ b/core/embed/sec/optiga/inc/sec/optiga_commands.h
@@ -17,8 +17,7 @@
* along with this program. If not, see <http://www.gnu.org/licenses/>.
*/
-#ifndef TREZORHAL_OPTIGA_COMMANDS_H
-#define TREZORHAL_OPTIGA_COMMANDS_H
+#pragma once
#include <trezor_types.h>
@@ -258,9 +257,3 @@ optiga_result optiga_set_priv_key(uint16_t oid, const uint8_t priv_key[32]);
optiga_result optiga_clear_all_auto_states(void);
optiga_result optiga_reset_counter(uint16_t oid, uint32_t limit);
void optiga_reset_counter_time(uint32_t *time_ms);
-
-#if !PRODUCTION
-void optiga_command_set_log_hex(optiga_log_hex_t f);
-#endif
-
-#endif
diff --git a/core/embed/sec/optiga/inc/sec/optiga_common.h b/core/embed/sec/optiga/inc/sec/optiga_common.h
index 6447e7ca..612bf8ee 100644
--- a/core/embed/sec/optiga/inc/sec/optiga_common.h
+++ b/core/embed/sec/optiga/inc/sec/optiga_common.h
@@ -17,8 +17,7 @@
* along with this program. If not, see <http://www.gnu.org/licenses/>.
*/
-#ifndef TREZORHAL_OPTIGA_COMMON_H
-#define TREZORHAL_OPTIGA_COMMON_H
+#pragma once
#include <trezor_types.h>
@@ -38,10 +37,3 @@ typedef enum _optiga_result {
} optiga_result;
typedef secbool (*optiga_ui_progress_t)(void);
-
-#if !PRODUCTION
-typedef void (*optiga_log_hex_t)(const char *prefix, const uint8_t *data,
- size_t data_size);
-#endif
-
-#endif
diff --git a/core/embed/sec/optiga/inc/sec/optiga_transport.h b/core/embed/sec/optiga/inc/sec/optiga_transport.h
index 78178cfe..e6399005 100644
--- a/core/embed/sec/optiga/inc/sec/optiga_transport.h
+++ b/core/embed/sec/optiga/inc/sec/optiga_transport.h
@@ -17,8 +17,7 @@
* along with this program. If not, see <http://www.gnu.org/licenses/>.
*/
-#ifndef TREZORHAL_OPTIGA_TRANSPORT_H
-#define TREZORHAL_OPTIGA_TRANSPORT_H
+#pragma once
#include <trezor_types.h>
@@ -48,9 +47,3 @@ optiga_result optiga_soft_reset(void);
optiga_result optiga_set_data_reg_len(size_t size);
void optiga_set_ui_progress(optiga_ui_progress_t f);
-
-#if !PRODUCTION
-void optiga_transport_set_log_hex(optiga_log_hex_t f);
-#endif
-
-#endif
diff --git a/core/embed/sec/optiga/optiga_commands.c b/core/embed/sec/optiga/optiga_commands.c
index a8d32bd2..eab97400 100644
--- a/core/embed/sec/optiga/optiga_commands.c
+++ b/core/embed/sec/optiga/optiga_commands.c
@@ -27,6 +27,7 @@
#include <trezor_rtl.h>
+#include <rtl/logging.h>
#include <sec/optiga_commands.h>
#include <sec/optiga_transport.h>
#include "der.h"
@@ -36,6 +37,8 @@
#include "nist256p1.h"
#include "sha2.h"
+LOG_DECLARE(optiga)
+
// The throttling delay when the security event counter is at its maximum.
#define OPTIGA_T_MAX_MS 5000
@@ -64,17 +67,6 @@ const optiga_metadata_item OPTIGA_META_KEY_USE_KEYAGREE =
const optiga_metadata_item OPTIGA_META_VERSION_DEFAULT = {
(const uint8_t[]){0x00, 0x00}, 2};
-#if PRODUCTION
-#define OPTIGA_LOG(prefix, data, data_size)
-#else
-static optiga_log_hex_t log_hex = NULL;
-void optiga_command_set_log_hex(optiga_log_hex_t f) { log_hex = f; }
-#define OPTIGA_LOG(prefix, data, data_size) \
- if (log_hex != NULL) { \
- log_hex(prefix, data, data_size); \
- }
-#endif
-
static bool auto_states_add(optiga_oid oid) {
if (auto_states_count >= AUTO_STATES_MAX_COUNT) {
return false;
@@ -125,13 +117,13 @@ static optiga_result process_output(uint8_t **out_data, size_t *out_size) {
// Check response status code.
if (tx_buffer[0] != 0) {
- OPTIGA_LOG("FAILED", NULL, 0)
+ LOG_DBG("FAILED");
return OPTIGA_ERR_CMD;
}
*out_data = tx_buffer + 4;
*out_size = tx_size - 4;
- OPTIGA_LOG("SUCCESS", *out_data, *out_size)
+ LOG_HEXDUMP_DBG("SUCCESS", *out_data, *out_size);
return OPTIGA_SUCCESS;
}
@@ -339,7 +331,7 @@ optiga_result optiga_open_application(void) {
0x65, 0x6E, 0x41, 0x75, 0x74, 0x68, 0x41, 0x70, 0x70, 0x6C,
};
- OPTIGA_LOG(__func__, OPEN_APP, sizeof(OPEN_APP))
+ LOG_HEXDUMP_DBG(__func__, OPEN_APP, sizeof(OPEN_APP));
optiga_result ret = optiga_execute_command(
OPEN_APP, sizeof(OPEN_APP), tx_buffer, sizeof(tx_buffer), &tx_size);
if (ret != OPTIGA_SUCCESS) {
@@ -358,7 +350,7 @@ optiga_result optiga_get_error_code(uint8_t *error_code) {
write_uint16(&ptr, OPTIGA_OID_ERROR_CODE);
- OPTIGA_LOG(__func__, tx_buffer, tx_size)
+ LOG_HEXDUMP_DBG(__func__, tx_buffer, tx_size);
optiga_result ret = optiga_execute_command(tx_buffer, tx_size, tx_buffer,
sizeof(tx_buffer), &tx_size);
if (ret != OPTIGA_SUCCESS) {
@@ -382,7 +374,7 @@ optiga_result optiga_get_data_object(uint16_t oid, bool get_metadata,
write_uint16(&ptr, oid);
- OPTIGA_LOG(__func__, tx_buffer, tx_size)
+ LOG_HEXDUMP_DBG(__func__, tx_buffer, tx_size);
optiga_result ret = optiga_execute_command(tx_buffer, tx_size, tx_buffer,
sizeof(tx_buffer), &tx_size);
if (ret != OPTIGA_SUCCESS) {
@@ -423,7 +415,7 @@ optiga_result optiga_set_data_object(uint16_t oid, bool set_metadata,
memcpy(ptr, data, data_size);
}
- OPTIGA_LOG(__func__, tx_buffer, tx_size)
+ LOG_HEXDUMP_DBG(__func__, tx_buffer, tx_size);
optiga_result ret = optiga_execute_command(tx_buffer, tx_size, tx_buffer,
sizeof(tx_buffer), &tx_size);
if (ret != OPTIGA_SUCCESS) {
@@ -495,7 +487,7 @@ optiga_result optiga_get_random(uint8_t *random, size_t random_size) {
write_uint16(&ptr, random_size);
- OPTIGA_LOG(__func__, tx_buffer, tx_size)
+ LOG_HEXDUMP_DBG(__func__, tx_buffer, tx_size);
optiga_result ret = optiga_execute_command(tx_buffer, tx_size, tx_buffer,
sizeof(tx_buffer), &tx_size);
if (ret != OPTIGA_SUCCESS) {
@@ -533,7 +525,7 @@ optiga_result optiga_encrypt_sym(optiga_sym_mode mode, uint16_t oid,
*(ptr++) = 0x01; // start and final data block
write_prefixed_data(&ptr, input, input_size);
- OPTIGA_LOG(__func__, tx_buffer, tx_size)
+ LOG_HEXDUMP_DBG(__func__, tx_buffer, tx_size);
optiga_result ret = optiga_execute_command(tx_buffer, tx_size, tx_buffer,
sizeof(tx_buffer), &tx_size);
if (ret == OPTIGA_SUCCESS) {
@@ -581,7 +573,7 @@ optiga_result optiga_set_auto_state(uint16_t nonce_oid, uint16_t key_oid,
*(ptr++) = 0x41; // pre-pending optional data tag
write_uint16(&ptr, 0);
- OPTIGA_LOG(__func__, tx_buffer, tx_size)
+ LOG_HEXDUMP_DBG(__func__, tx_buffer, tx_size);
optiga_result ret = optiga_execute_command(tx_buffer, tx_size, tx_buffer,
sizeof(tx_buffer), &tx_size);
@@ -608,7 +600,7 @@ optiga_result optiga_set_auto_state(uint16_t nonce_oid, uint16_t key_oid,
write_uint16(&ptr, SHA256_DIGEST_LENGTH);
hmac_sha256(key, key_size, nonce, sizeof(nonce), ptr);
- OPTIGA_LOG(__func__, tx_buffer, tx_size)
+ LOG_HEXDUMP_DBG(__func__, tx_buffer, tx_size);
// The auto-state is added before the command is actually executed. Otherwise,
// it could happen that the command succeeded, but an error occurred during
// the receipt of the response. In such a case, the auto-state couldn't be
@@ -646,7 +638,7 @@ optiga_result optiga_clear_auto_state(uint16_t key_oid) {
*(ptr++) = 0x43; // verification value tag
write_uint16(&ptr, 0); // verification value length
- OPTIGA_LOG(__func__, tx_buffer, tx_size)
+ LOG_HEXDUMP_DBG(__func__, tx_buffer, tx_size);
optiga_result ret = optiga_execute_command(tx_buffer, tx_size, tx_buffer,
sizeof(tx_buffer), &tx_size);
if (ret != OPTIGA_SUCCESS) {
@@ -690,7 +682,7 @@ optiga_result optiga_calc_sign(uint16_t oid, const uint8_t *digest,
write_uint16(&ptr, 2);
write_uint16(&ptr, oid);
- OPTIGA_LOG(__func__, tx_buffer, tx_size)
+ LOG_HEXDUMP_DBG(__func__, tx_buffer, tx_size);
optiga_result ret = optiga_execute_command(tx_buffer, tx_size, tx_buffer,
sizeof(tx_buffer), &tx_size);
if (ret != OPTIGA_SUCCESS) {
@@ -758,7 +750,7 @@ optiga_result optiga_verify_sign(optiga_curve curve, const uint8_t *public_key,
*(ptr++) = 0x06; // public key tag
write_prefixed_data(&ptr, public_key, public_key_size);
- OPTIGA_LOG(__func__, tx_buffer, tx_size)
+ LOG_HEXDUMP_DBG(__func__, tx_buffer, tx_size);
optiga_result ret = optiga_execute_command(tx_buffer, tx_size, tx_buffer,
sizeof(tx_buffer), &tx_size);
if (ret != OPTIGA_SUCCESS) {
@@ -791,7 +783,7 @@ optiga_result optiga_gen_key_pair(optiga_curve curve, optiga_key_usage usage,
write_uint16(&ptr, 1);
*(ptr++) = usage;
- OPTIGA_LOG(__func__, tx_buffer, tx_size)
+ LOG_HEXDUMP_DBG(__func__, tx_buffer, tx_size);
optiga_result ret = optiga_execute_command(tx_buffer, tx_size, tx_buffer,
sizeof(tx_buffer), &tx_size);
if (ret != OPTIGA_SUCCESS) {
@@ -826,7 +818,7 @@ optiga_result optiga_gen_sym_key(optiga_aes algorithm, optiga_key_usage usage,
write_uint16(&ptr, 1);
*(ptr++) = usage;
- OPTIGA_LOG(__func__, tx_buffer, tx_size)
+ LOG_HEXDUMP_DBG(__func__, tx_buffer, tx_size);
optiga_result ret = optiga_execute_command(tx_buffer, tx_size, tx_buffer,
sizeof(tx_buffer), &tx_size);
if (ret != OPTIGA_SUCCESS) {
@@ -876,7 +868,7 @@ optiga_result optiga_calc_ssec(optiga_curve curve, uint16_t oid,
*(ptr++) = 0x07; // export tag
write_uint16(&ptr, 0);
- OPTIGA_LOG(__func__, tx_buffer, tx_size)
+ LOG_HEXDUMP_DBG(__func__, tx_buffer, tx_size);
optiga_result ret = optiga_execute_command(tx_buffer, tx_size, tx_buffer,
sizeof(tx_buffer), &tx_size);
if (ret != OPTIGA_SUCCESS) {
@@ -936,7 +928,7 @@ optiga_result optiga_derive_key(optiga_key_derivation deriv, uint16_t oid,
*(ptr++) = 0x07; // export tag
write_uint16(&ptr, 0);
- OPTIGA_LOG(__func__, tx_buffer, tx_size)
+ LOG_HEXDUMP_DBG(__func__, tx_buffer, tx_size);
optiga_result ret = optiga_execute_command(tx_buffer, tx_size, tx_buffer,
sizeof(tx_buffer), &tx_size);
if (ret == OPTIGA_SUCCESS) {
@@ -1065,7 +1057,7 @@ optiga_result optiga_set_priv_key(uint16_t oid, const uint8_t priv_key[32]) {
return OPTIGA_ERR_PROCESS;
}
- OPTIGA_LOG(__func__, sop_cmd1, sizeof(sop_cmd1))
+ LOG_HEXDUMP_DBG(__func__, sop_cmd1, sizeof(sop_cmd1));
ret = optiga_execute_command(sop_cmd1, sizeof(sop_cmd1), tx_buffer,
sizeof(tx_buffer), &tx_size);
if (ret != OPTIGA_SUCCESS) {
@@ -1079,7 +1071,7 @@ optiga_result optiga_set_priv_key(uint16_t oid, const uint8_t priv_key[32]) {
return ret;
}
- OPTIGA_LOG(__func__, sop_cmd2, sizeof(sop_cmd2))
+ LOG_HEXDUMP_DBG(__func__, sop_cmd2, sizeof(sop_cmd2));
ret = optiga_execute_command(sop_cmd2, sizeof(sop_cmd2), tx_buffer,
sizeof(tx_buffer), &tx_size);
memzero(sop_cmd2, sizeof(sop_cmd2));
diff --git a/core/embed/sec/optiga/optiga_init.c b/core/embed/sec/optiga/optiga_init.c
index 3e5dbcd7..badd5028 100644
--- a/core/embed/sec/optiga/optiga_init.c
+++ b/core/embed/sec/optiga/optiga_init.c
@@ -30,31 +30,6 @@
#include "memzero.h"
-#ifdef USE_DBG_CONSOLE
-#include <sys/dbg_console.h>
-#endif
-
-#if defined(USE_DBG_CONSOLE) && defined(USE_OPTIGA_LOGGING)
-#include <inttypes.h>
-#if 1 // color log
-#define OPTIGA_LOG_FORMAT \
- "%d.%03d \x1b[35moptiga\x1b[0m \x1b[32mDEBUG\x1b[0m %s: "
-#else
-#define OPTIGA_LOG_FORMAT "%d.%03d optiga DEBUG %s: "
-#endif
-static void optiga_log_hex(const char *prefix, const uint8_t *data,
- size_t data_size) {
- ticks_t now = hal_ticks_ms();
- uint32_t sec = now / 1000;
- uint32_t msec = now % 1000;
- dbg_console_printf(OPTIGA_LOG_FORMAT, sec, msec, prefix);
- for (size_t i = 0; i < data_size; i++) {
- dbg_console_printf("%02x", data[i]);
- }
- dbg_console_printf("\n");
-}
-#endif
-
optiga_result optiga_init() {
optiga_transport_power_up();
return optiga_transport_open_channel();
@@ -70,13 +45,6 @@ void optiga_close_channel() { optiga_transport_close_channel(); }
void optiga_power_down() { optiga_transport_power_down(); }
void optiga_init_and_configure(void) {
-#if defined(USE_DBG_CONSOLE) && defined(USE_OPTIGA_LOGGING)
- // command log is relatively quiet so we enable it in debug builds
- optiga_command_set_log_hex(optiga_log_hex);
- // transport log can be spammy, uncomment if you want it:
- // optiga_transport_set_log_hex(optiga_log_hex);
-#endif
-
optiga_init();
uint8_t secret[OPTIGA_PAIRING_SECRET_SIZE] = {0};
diff --git a/core/embed/sec/optiga/optiga_transport.c b/core/embed/sec/optiga/optiga_transport.c
index f64ef3b9..f046c081 100644
--- a/core/embed/sec/optiga/optiga_transport.c
+++ b/core/embed/sec/optiga/optiga_transport.c
@@ -28,6 +28,8 @@
#include <trezor_rtl.h>
#include <io/i2c_bus.h>
+#include <rtl/logging.h>
+#include <rtl/strutils.h>
#include <sec/optiga_hal.h>
#include <sec/optiga_transport.h>
#include <sys/systick.h>
@@ -35,6 +37,8 @@
#include "memzero.h"
#include "tls_prf.h"
+LOG_DECLARE(optiga_transport)
+
// Maximum possible packet size that can be transmitted.
#define OPTIGA_MAX_PACKET_SIZE (OPTIGA_DATA_REG_LEN - 5)
@@ -143,33 +147,32 @@ static uint8_t sec_chan_buffer[OPTIGA_MAX_APDU_SIZE + SEC_CHAN_OVERHEAD_SIZE] =
{0};
static size_t sec_chan_size = 0;
-#if PRODUCTION
-#define OPTIGA_LOG(prefix, data, data_size)
-#else
-static optiga_log_hex_t log_hex = NULL;
-void optiga_transport_set_log_hex(optiga_log_hex_t f) { log_hex = f; }
-#define OPTIGA_LOG(prefix, data, data_size) \
- if (log_hex != NULL) { \
- static uint8_t prev_data[4]; \
- static size_t prev_size = 0; \
- static bool repeated = false; \
- if (prev_size == data_size && memcmp(data, prev_data, data_size) == 0) { \
- if (!repeated) { \
- repeated = true; \
- log_hex(prefix "(REPEATED) ", data, data_size); \
- } \
- } else { \
- repeated = false; \
- if (data_size <= sizeof(prev_data)) { \
- memcpy(prev_data, data, data_size); \
- prev_size = data_size; \
- } else { \
- prev_size = 0; \
- } \
- log_hex(prefix, data, data_size); \
- } \
- }
-#endif
+static void optiga_log_transport(const char *prefix, const uint8_t *data,
+ size_t data_size) {
+ if (LOG_MODULE_MAX_LEVEL >= LOG_LEVEL_DBG) {
+ static uint8_t prev_data[4];
+ static size_t prev_size = 0;
+ static bool repeated = false;
+ if (prev_size == data_size && memcmp(data, prev_data, data_size) == 0) {
+ if (!repeated) {
+ repeated = true;
+ char prefix_buf[16] = "";
+ cstr_append(prefix_buf, sizeof(prefix_buf), prefix);
+ cstr_append(prefix_buf, sizeof(prefix_buf), " (REPEATED)");
+ LOG_HEXDUMP_DBG(prefix_buf, data, data_size);
+ }
+ } else {
+ repeated = false;
+ if (data_size <= sizeof(prev_data)) {
+ memcpy(prev_data, data, data_size);
+ prev_size = data_size;
+ } else {
+ prev_size = 0;
+ }
+ LOG_HEXDUMP_DBG(prefix, data, data_size);
+ }
+ }
+}
void optiga_set_ui_progress(optiga_ui_progress_t f) { ui_progress = f; }
@@ -220,7 +223,7 @@ void optiga_transport_close_channel(void) {
}
static optiga_result optiga_i2c_write(const uint8_t *data, uint16_t data_size) {
- OPTIGA_LOG(">>>", data, data_size)
+ optiga_log_transport(">>>", data, data_size);
i2c_op_t ops[] = {
{
@@ -272,7 +275,7 @@ static optiga_result optiga_i2c_read(uint8_t *buffer, uint16_t buffer_size) {
systick_delay_ms(1);
if (I2C_STATUS_OK == i2c_bus_submit_and_wait(i2c_bus, &pkt)) {
- OPTIGA_LOG("<<<", buffer, buffer_size)
+ optiga_log_transport("<<<", buffer, buffer_size);
return OPTIGA_SUCCESS;
}
}
diff --git a/core/embed/sys/dbg/inc/sys/syslog_config.h b/core/embed/sys/dbg/inc/sys/syslog_config.h
index 7ba47eea..1839bad1 100644
--- a/core/embed/sys/dbg/inc/sys/syslog_config.h
+++ b/core/embed/sys/dbg/inc/sys/syslog_config.h
@@ -19,6 +19,10 @@
*/
#pragma once
+#ifdef TREZOR_EMULATOR
+#define SYSLOG_DEFAULT_LOG_LEVEL LOG_LEVEL_INF
+#endif
+
// Maximum default log level for all modules if not overriden in
// by defining SYSLOG_<module_name>_MAX_LOG_LEVEL during compilation
#ifndef SYSLOG_DEFAULT_LOG_LEVEL
@@ -28,10 +32,30 @@
// Maximum default log level for specific modules
// (can be overriden by defining SYSLOG_<module_name>_MAX_LOG_LEVEL)
+#ifndef SYSLOG_emulator_MAX_LOG_LEVEL
+#define SYSLOG_emulator_MAX_LOG_LEVEL SYSLOG_DEFAULT_LOG_LEVEL
+#endif
+
+#ifndef SYSLOG_coreapp_main_MAX_LOG_LEVEL
+#define SYSLOG_coreapp_main_MAX_LOG_LEVEL SYSLOG_DEFAULT_LOG_LEVEL
+#endif
+
+#ifndef SYSLOG_bootutils_MAX_LOG_LEVEL
+#define SYSLOG_bootutils_MAX_LOG_LEVEL SYSLOG_DEFAULT_LOG_LEVEL
+#endif
+
#ifndef SYSLOG_touch_driver_MAX_LOG_LEVEL
#define SYSLOG_touch_driver_MAX_LOG_LEVEL SYSLOG_DEFAULT_LOG_LEVEL
#endif
+#ifndef SYSLOG_display_driver_MAX_LOG_LEVEL
+#define SYSLOG_display_driver_MAX_LOG_LEVEL SYSLOG_DEFAULT_LOG_LEVEL
+#endif
+
+#ifndef SYSLOG_ble_driver_MAX_LOG_LEVEL
+#define SYSLOG_ble_driver_MAX_LOG_LEVEL SYSLOG_DEFAULT_LOG_LEVEL
+#endif
+
// Optiga command log is relatively quiet
#ifndef SYSLOG_optiga_MAX_LOG_LEVEL
#define SYSLOG_optiga_MAX_LOG_LEVEL SYSLOG_DEFAULT_LOG_LEVEL
diff --git a/core/embed/sys/startup/unix/bootutils.c b/core/embed/sys/startup/unix/bootutils.c
index 0fdb2c91..feade233 100644
--- a/core/embed/sys/startup/unix/bootutils.c
+++ b/core/embed/sys/startup/unix/bootutils.c
@@ -21,10 +21,13 @@
#include <stdlib.h>
+#include <rtl/logging.h>
#include <sys/bootargs.h>
#include <sys/bootutils.h>
#include <sys/systick.h>
+LOG_DECLARE(bootutils)
+
// Holds the 'command' for the next reboot.
static boot_command_t g_boot_command;
@@ -56,25 +59,25 @@ void bootargs_get_args(boot_args_t* dest) {
}
__attribute__((noreturn)) void reboot_device(void) {
- printf("reboot (normal)\n");
+ LOG_WARN("reboot (normal)");
exit(3);
}
__attribute__((noreturn)) void reboot_to_bootloader(void) {
- printf("reboot (to bootloader)\n");
+ LOG_WARN("reboot (to bootloader)");
exit(3);
}
__attribute__((noreturn)) void reboot_and_upgrade(const uint8_t hash[32]) {
- printf("reboot (upgrade)\n");
+ LOG_WARN("reboot (upgrade)");
exit(3);
}
__attribute__((noreturn)) void reboot_to_off(void) {
- printf("reboot (power off)\n");
+ LOG_WARN("reboot (power off)");
exit(3);
}
@@ -83,7 +86,7 @@ __attribute__((noreturn)) void reboot_and_wipe(
const bootutils_wipe_info_t* info) {
show_wipe_info(info);
- printf("reboot (wipe)\n");
+ LOG_WARN("reboot (wipe)");
systick_delay_ms(3000);
@@ -91,7 +94,7 @@ __attribute__((noreturn)) void reboot_and_wipe(
}
__attribute__((noreturn)) void reboot_or_halt_after_rsod(void) {
- printf("reboot (with timeout)\n");
+ LOG_WARN("reboot (with timeout)");
// Wait some time to let the user see the displayed
// message before shutting down
Why this scored 15/100
Community notes
Notes can correct, qualify, or add evidence to the AI analysis. Every note shown here has been validated by a human moderator.
The AI analysis stands alone for now. Submit a note if you can add evidence or important context.