From 9b9edf2fbffa2fc671a67ec2b629cc322952cd4a Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?=E3=81=82=E3=81=8F?= Date: Thu, 14 Apr 2022 19:41:15 +0300 Subject: [PATCH] [FL-2460] Rpc: debug request logging and cli log command (#1114) * Rpc: debug request logging * Furi, Cli: replace global thread callback with local ring buffers, fix log command --- applications/cli/cli_commands.c | 26 +++++++++++--- applications/rpc/rpc_app.c | 6 ++++ applications/rpc/rpc_gui.c | 14 +++++++- applications/rpc/rpc_storage.c | 29 +++++++++++++++- applications/rpc/rpc_system.c | 24 ++++++++++++- core/furi/stdglue.c | 31 ----------------- core/furi/stdglue.h | 9 ----- .../targets/f7/furi_hal/furi_hal_console.c | 34 +++++++++++++++---- .../targets/f7/furi_hal/furi_hal_console.h | 4 +++ 9 files changed, 124 insertions(+), 53 deletions(-) diff --git a/applications/cli/cli_commands.c b/applications/cli/cli_commands.c index 58c13160..a58ddd49 100644 --- a/applications/cli/cli_commands.c +++ b/applications/cli/cli_commands.c @@ -6,6 +6,7 @@ #include #include #include +#include // Close to ISO, `date +'%Y-%m-%d %H:%M:%S %u'` #define CLI_DATE_FORMAT "%.4d-%.2d-%.2d %.2d:%.2d:%.2d %d" @@ -126,11 +127,28 @@ void cli_command_date(Cli* cli, string_t args, void* context) { } } +#define CLI_COMMAND_LOG_RING_SIZE 2048 +#define CLI_COMMAND_LOG_BUFFER_SIZE 64 + +void cli_command_log_tx_callback(const uint8_t* buffer, size_t size, void* context) { + xStreamBufferSend(context, buffer, size, 0); +} + void cli_command_log(Cli* cli, string_t args, void* context) { - furi_stdglue_set_global_stdout_callback(cli_stdout_callback); - printf("Press any key to stop...\r\n"); - cli_getc(cli); - furi_stdglue_set_global_stdout_callback(NULL); + StreamBufferHandle_t ring = xStreamBufferCreate(CLI_COMMAND_LOG_RING_SIZE, 1); + uint8_t buffer[CLI_COMMAND_LOG_BUFFER_SIZE]; + + furi_hal_console_set_tx_callback(cli_command_log_tx_callback, ring); + + printf("Press CTRL+C to stop...\r\n"); + while(!cli_cmd_interrupt_received(cli)) { + size_t ret = xStreamBufferReceive(ring, buffer, CLI_COMMAND_LOG_BUFFER_SIZE, 50); + cli_write(cli, buffer, ret); + } + + furi_hal_console_set_tx_callback(NULL, NULL); + + vStreamBufferDelete(ring); } void cli_command_vibro(Cli* cli, string_t args, void* context) { diff --git a/applications/rpc/rpc_app.c b/applications/rpc/rpc_app.c index c35decf0..728c2052 100644 --- a/applications/rpc/rpc_app.c +++ b/applications/rpc/rpc_app.c @@ -4,12 +4,16 @@ #include #include +#define TAG "RpcSystemApp" + static void rpc_system_app_start_process(const PB_Main* request, void* context) { furi_assert(request); furi_assert(request->which_content == PB_Main_app_start_request_tag); RpcSession* session = (RpcSession*)context; furi_assert(session); + FURI_LOG_D(TAG, "Start"); + PB_CommandStatus result = PB_CommandStatus_ERROR_APP_CANT_START; Loader* loader = furi_record_open("loader"); @@ -43,6 +47,8 @@ static void rpc_system_app_lock_status_process(const PB_Main* request, void* con RpcSession* session = (RpcSession*)context; furi_assert(session); + FURI_LOG_D(TAG, "LockStatus"); + Loader* loader = furi_record_open("loader"); PB_Main response = { diff --git a/applications/rpc/rpc_gui.c b/applications/rpc/rpc_gui.c index b67035ac..f390d983 100644 --- a/applications/rpc/rpc_gui.c +++ b/applications/rpc/rpc_gui.c @@ -65,8 +65,10 @@ static int32_t rpc_system_gui_screen_stream_frame_transmit_thread(void* context) static void rpc_system_gui_start_screen_stream_process(const PB_Main* request, void* context) { furi_assert(request); furi_assert(context); - RpcGuiSystem* rpc_gui = context; + FURI_LOG_D(TAG, "StartScreenStream"); + + RpcGuiSystem* rpc_gui = context; RpcSession* session = rpc_gui->session; furi_assert(session); @@ -103,6 +105,8 @@ static void rpc_system_gui_stop_screen_stream_process(const PB_Main* request, vo furi_assert(request); furi_assert(context); + FURI_LOG_D(TAG, "StopScreenStream"); + RpcGuiSystem* rpc_gui = context; RpcSession* session = rpc_gui->session; furi_assert(session); @@ -132,6 +136,8 @@ static void furi_assert(request->which_content == PB_Main_gui_send_input_event_request_tag); furi_assert(context); + FURI_LOG_D(TAG, "SendInputEvent"); + RpcGuiSystem* rpc_gui = context; RpcSession* session = rpc_gui->session; furi_assert(session); @@ -220,6 +226,8 @@ static void rpc_system_gui_start_virtual_display_process(const PB_Main* request, furi_assert(request); furi_assert(context); + FURI_LOG_D(TAG, "StartVirtualDisplay"); + RpcGuiSystem* rpc_gui = context; RpcSession* session = rpc_gui->session; furi_assert(session); @@ -259,6 +267,8 @@ static void rpc_system_gui_stop_virtual_display_process(const PB_Main* request, furi_assert(request); furi_assert(context); + FURI_LOG_D(TAG, "StopVirtualDisplay"); + RpcGuiSystem* rpc_gui = context; RpcSession* session = rpc_gui->session; furi_assert(session); @@ -282,6 +292,8 @@ static void rpc_system_gui_virtual_display_frame_process(const PB_Main* request, furi_assert(request); furi_assert(context); + FURI_LOG_D(TAG, "VirtualDisplayFrame"); + RpcGuiSystem* rpc_gui = context; RpcSession* session = rpc_gui->session; furi_assert(session); diff --git a/applications/rpc/rpc_storage.c b/applications/rpc/rpc_storage.c index 97d9ab62..a21fec8e 100644 --- a/applications/rpc/rpc_storage.c +++ b/applications/rpc/rpc_storage.c @@ -12,7 +12,8 @@ #include #include -#define RPC_TAG "RPC_STORAGE" +#define TAG "RpcStorage" + #define MAX_NAME_LENGTH 255 static const size_t MAX_DATA_SIZE = 512; @@ -106,6 +107,8 @@ static void rpc_system_storage_info_process(const PB_Main* request, void* contex furi_assert(context); furi_assert(request->which_content == PB_Main_storage_info_request_tag); + FURI_LOG_D(TAG, "Info"); + RpcStorageSystem* rpc_storage = context; RpcSession* session = rpc_storage->session; furi_assert(session); @@ -140,6 +143,8 @@ static void rpc_system_storage_stat_process(const PB_Main* request, void* contex furi_assert(context); furi_assert(request->which_content == PB_Main_storage_stat_request_tag); + FURI_LOG_D(TAG, "Stat"); + RpcStorageSystem* rpc_storage = context; RpcSession* session = rpc_storage->session; furi_assert(session); @@ -205,6 +210,8 @@ static void rpc_system_storage_list_process(const PB_Main* request, void* contex furi_assert(context); furi_assert(request->which_content == PB_Main_storage_list_request_tag); + FURI_LOG_D(TAG, "List"); + RpcStorageSystem* rpc_storage = context; RpcSession* session = rpc_storage->session; furi_assert(session); @@ -273,6 +280,8 @@ static void rpc_system_storage_read_process(const PB_Main* request, void* contex furi_assert(context); furi_assert(request->which_content == PB_Main_storage_read_request_tag); + FURI_LOG_D(TAG, "Read"); + RpcStorageSystem* rpc_storage = context; RpcSession* session = rpc_storage->session; furi_assert(session); @@ -330,6 +339,8 @@ static void rpc_system_storage_write_process(const PB_Main* request, void* conte furi_assert(context); furi_assert(request->which_content == PB_Main_storage_write_request_tag); + FURI_LOG_D(TAG, "Write"); + RpcStorageSystem* rpc_storage = context; RpcSession* session = rpc_storage->session; furi_assert(session); @@ -395,6 +406,9 @@ static void rpc_system_storage_delete_process(const PB_Main* request, void* cont furi_assert(request); furi_assert(request->which_content == PB_Main_storage_delete_request_tag); furi_assert(context); + + FURI_LOG_D(TAG, "Delete"); + RpcStorageSystem* rpc_storage = context; RpcSession* session = rpc_storage->session; furi_assert(session); @@ -433,6 +447,9 @@ static void rpc_system_storage_mkdir_process(const PB_Main* request, void* conte furi_assert(request); furi_assert(request->which_content == PB_Main_storage_mkdir_request_tag); furi_assert(context); + + FURI_LOG_D(TAG, "Mkdir"); + RpcStorageSystem* rpc_storage = context; RpcSession* session = rpc_storage->session; furi_assert(session); @@ -456,6 +473,9 @@ static void rpc_system_storage_md5sum_process(const PB_Main* request, void* cont furi_assert(request); furi_assert(request->which_content == PB_Main_storage_md5sum_request_tag); furi_assert(context); + + FURI_LOG_D(TAG, "Md5sum"); + RpcStorageSystem* rpc_storage = context; RpcSession* session = rpc_storage->session; furi_assert(session); @@ -521,6 +541,9 @@ static void rpc_system_storage_rename_process(const PB_Main* request, void* cont furi_assert(request); furi_assert(request->which_content == PB_Main_storage_rename_request_tag); furi_assert(context); + + FURI_LOG_D(TAG, "Rename"); + RpcStorageSystem* rpc_storage = context; RpcSession* session = rpc_storage->session; furi_assert(session); @@ -544,6 +567,8 @@ static void rpc_system_storage_backup_create_process(const PB_Main* request, voi furi_assert(request); furi_assert(request->which_content == PB_Main_storage_backup_create_request_tag); + FURI_LOG_D(TAG, "BackupCreate"); + RpcSession* session = (RpcSession*)context; furi_assert(session); @@ -567,6 +592,8 @@ static void rpc_system_storage_backup_restore_process(const PB_Main* request, vo furi_assert(request); furi_assert(request->which_content == PB_Main_storage_backup_restore_request_tag); + FURI_LOG_D(TAG, "BackupRestore"); + RpcSession* session = (RpcSession*)context; furi_assert(session); diff --git a/applications/rpc/rpc_system.c b/applications/rpc/rpc_system.c index 6ea3b02e..f54bb197 100644 --- a/applications/rpc/rpc_system.c +++ b/applications/rpc/rpc_system.c @@ -7,6 +7,8 @@ #include "rpc_i.h" +#define TAG "RpcSystem" + typedef struct { RpcSession* session; PB_Main* response; @@ -16,6 +18,8 @@ static void rpc_system_system_ping_process(const PB_Main* request, void* context furi_assert(request); furi_assert(request->which_content == PB_Main_system_ping_request_tag); + FURI_LOG_D(TAG, "Ping"); + RpcSession* session = (RpcSession*)context; furi_assert(session); @@ -46,6 +50,8 @@ static void rpc_system_system_reboot_process(const PB_Main* request, void* conte furi_assert(request); furi_assert(request->which_content == PB_Main_system_reboot_request_tag); + FURI_LOG_D(TAG, "Reboot"); + RpcSession* session = (RpcSession*)context; furi_assert(session); @@ -84,6 +90,8 @@ static void rpc_system_system_device_info_process(const PB_Main* request, void* furi_assert(request); furi_assert(request->which_content == PB_Main_system_device_info_request_tag); + FURI_LOG_D(TAG, "DeviceInfo"); + RpcSession* session = (RpcSession*)context; furi_assert(session); @@ -105,6 +113,8 @@ static void rpc_system_system_get_datetime_process(const PB_Main* request, void* furi_assert(request); furi_assert(request->which_content == PB_Main_system_get_datetime_request_tag); + FURI_LOG_D(TAG, "GetDatetime"); + RpcSession* session = (RpcSession*)context; furi_assert(session); @@ -132,6 +142,8 @@ static void rpc_system_system_set_datetime_process(const PB_Main* request, void* furi_assert(request); furi_assert(request->which_content == PB_Main_system_set_datetime_request_tag); + FURI_LOG_D(TAG, "SetDatetime"); + RpcSession* session = (RpcSession*)context; furi_assert(session); @@ -158,6 +170,8 @@ static void rpc_system_system_factory_reset_process(const PB_Main* request, void furi_assert(request); furi_assert(request->which_content == PB_Main_system_factory_reset_request_tag); + FURI_LOG_D(TAG, "Reset"); + RpcSession* session = (RpcSession*)context; furi_assert(session); @@ -172,6 +186,8 @@ static void furi_assert(request); furi_assert(request->which_content == PB_Main_system_play_audiovisual_alert_request_tag); + FURI_LOG_D(TAG, "Alert"); + RpcSession* session = (RpcSession*)context; furi_assert(session); @@ -186,6 +202,8 @@ static void rpc_system_system_protobuf_version_process(const PB_Main* request, v furi_assert(request); furi_assert(request->which_content == PB_Main_system_protobuf_version_request_tag); + FURI_LOG_D(TAG, "ProtobufVersion"); + RpcSession* session = (RpcSession*)context; furi_assert(session); @@ -226,6 +244,8 @@ static void rpc_system_system_get_power_info_process(const PB_Main* request, voi furi_assert(request); furi_assert(request->which_content == PB_Main_system_power_info_request_tag); + FURI_LOG_D(TAG, "GetPowerInfo"); + RpcSession* session = (RpcSession*)context; furi_assert(session); @@ -248,6 +268,8 @@ static void rpc_system_system_update_request_process(const PB_Main* request, voi furi_assert(request); furi_assert(request->which_content == PB_Main_system_update_request_tag); + FURI_LOG_D(TAG, "SystemUpdate"); + RpcSession* session = (RpcSession*)context; furi_assert(session); @@ -305,4 +327,4 @@ void* rpc_system_system_alloc(RpcSession* session) { #endif return NULL; -} \ No newline at end of file +} diff --git a/core/furi/stdglue.c b/core/furi/stdglue.c index 52fb3fd9..4e727202 100644 --- a/core/furi/stdglue.c +++ b/core/furi/stdglue.c @@ -17,7 +17,6 @@ DICT_DEF2( typedef struct { osMutexId_t mutex; - FuriStdglueCallbackDict_t global_outputs; FuriStdglueCallbackDict_t thread_outputs; } FuriStdglue; @@ -31,17 +30,6 @@ static ssize_t stdout_write(void* _cookie, const char* data, size_t size) { if(state == osKernelRunning && thread_id && osMutexAcquire(furi_stdglue->mutex, osWaitForever) == osOK) { // We are in the thread context - // Handle global callbacks - FuriStdglueCallbackDict_it_t it; - for(FuriStdglueCallbackDict_it(it, furi_stdglue->global_outputs); - !FuriStdglueCallbackDict_end_p(it); - FuriStdglueCallbackDict_next(it)) { - osThreadId_t it_thread = (osThreadId_t)FuriStdglueCallbackDict_ref(it)->key; - FuriStdglueWriteCallback it_callback = FuriStdglueCallbackDict_ref(it)->value; - if(thread_id != it_thread) { - it_callback(_cookie, data, size); - } - } // Handle thread callbacks FuriStdglueWriteCallback* callback_ptr = FuriStdglueCallbackDict_get(furi_stdglue->thread_outputs, (uint32_t)thread_id); @@ -71,7 +59,6 @@ void furi_stdglue_init() { // Init outputs structures furi_stdglue->mutex = osMutexNew(NULL); furi_check(furi_stdglue->mutex); - FuriStdglueCallbackDict_init(furi_stdglue->global_outputs); FuriStdglueCallbackDict_init(furi_stdglue->thread_outputs); // Prepare and set stdout descriptor FILE* fp = fopencookie( @@ -87,24 +74,6 @@ void furi_stdglue_init() { stdout = fp; } -bool furi_stdglue_set_global_stdout_callback(FuriStdglueWriteCallback callback) { - furi_assert(furi_stdglue); - osThreadId_t thread_id = osThreadGetId(); - if(thread_id) { - furi_check(osMutexAcquire(furi_stdglue->mutex, osWaitForever) == osOK); - if(callback) { - FuriStdglueCallbackDict_set_at( - furi_stdglue->global_outputs, (uint32_t)thread_id, callback); - } else { - FuriStdglueCallbackDict_erase(furi_stdglue->global_outputs, (uint32_t)thread_id); - } - furi_check(osMutexRelease(furi_stdglue->mutex) == osOK); - return true; - } else { - return false; - } -} - bool furi_stdglue_set_thread_stdout_callback(FuriStdglueWriteCallback callback) { furi_assert(furi_stdglue); osThreadId_t thread_id = osThreadGetId(); diff --git a/core/furi/stdglue.h b/core/furi/stdglue.h index c83a443e..800fcf92 100644 --- a/core/furi/stdglue.h +++ b/core/furi/stdglue.h @@ -22,15 +22,6 @@ typedef void (*FuriStdglueWriteCallback)(void* _cookie, const char* data, size_t /** Initialized std library glue code */ void furi_stdglue_init(); -/** Set global STDOUT callback - * - * @param callback callback or NULL to clear - * - * @return true on success, otherwise fail - * @warning function is thread aware, use this API from the same thread - */ -bool furi_stdglue_set_global_stdout_callback(FuriStdglueWriteCallback callback); - /** Set STDOUT callback for your thread * * @param callback callback or NULL to clear diff --git a/firmware/targets/f7/furi_hal/furi_hal_console.c b/firmware/targets/f7/furi_hal/furi_hal_console.c index f3cf06da..e5db927b 100644 --- a/firmware/targets/f7/furi_hal/furi_hal_console.c +++ b/firmware/targets/f7/furi_hal/furi_hal_console.c @@ -18,11 +18,21 @@ #define CONSOLE_BAUDRATE 230400 #endif -volatile bool furi_hal_console_alive = false; +typedef struct { + bool alive; + FuriHalConsoleTxCallback tx_callback; + void* tx_callback_context; +} FuriHalConsole; + +FuriHalConsole furi_hal_console = { + .alive = false, + .tx_callback = NULL, + .tx_callback_context = NULL, +}; void furi_hal_console_init() { furi_hal_uart_init(FuriHalUartIdUSART1, CONSOLE_BAUDRATE); - furi_hal_console_alive = true; + furi_hal_console.alive = true; } void furi_hal_console_enable() { @@ -30,20 +40,32 @@ void furi_hal_console_enable() { while(!LL_USART_IsActiveFlag_TC(USART1)) ; furi_hal_uart_set_br(FuriHalUartIdUSART1, CONSOLE_BAUDRATE); - furi_hal_console_alive = true; + furi_hal_console.alive = true; } void furi_hal_console_disable() { while(!LL_USART_IsActiveFlag_TC(USART1)) ; - furi_hal_console_alive = false; + furi_hal_console.alive = false; +} + +void furi_hal_console_set_tx_callback(FuriHalConsoleTxCallback callback, void* context) { + FURI_CRITICAL_ENTER(); + furi_hal_console.tx_callback = callback; + furi_hal_console.tx_callback_context = context; + FURI_CRITICAL_EXIT(); } void furi_hal_console_tx(const uint8_t* buffer, size_t buffer_size) { - if(!furi_hal_console_alive) return; + if(!furi_hal_console.alive) return; FURI_CRITICAL_ENTER(); // Transmit data + + if(furi_hal_console.tx_callback) { + furi_hal_console.tx_callback(buffer, buffer_size, furi_hal_console.tx_callback_context); + } + furi_hal_uart_tx(FuriHalUartIdUSART1, (uint8_t*)buffer, buffer_size); // Wait for TC flag to be raised for last char while(!LL_USART_IsActiveFlag_TC(USART1)) @@ -52,7 +74,7 @@ void furi_hal_console_tx(const uint8_t* buffer, size_t buffer_size) { } void furi_hal_console_tx_with_new_line(const uint8_t* buffer, size_t buffer_size) { - if(!furi_hal_console_alive) return; + if(!furi_hal_console.alive) return; FURI_CRITICAL_ENTER(); // Transmit data diff --git a/firmware/targets/f7/furi_hal/furi_hal_console.h b/firmware/targets/f7/furi_hal/furi_hal_console.h index 637c17f6..104515ce 100644 --- a/firmware/targets/f7/furi_hal/furi_hal_console.h +++ b/firmware/targets/f7/furi_hal/furi_hal_console.h @@ -7,12 +7,16 @@ extern "C" { #endif +typedef void (*FuriHalConsoleTxCallback)(const uint8_t* buffer, size_t size, void* context); + void furi_hal_console_init(); void furi_hal_console_enable(); void furi_hal_console_disable(); +void furi_hal_console_set_tx_callback(FuriHalConsoleTxCallback callback, void* context); + void furi_hal_console_tx(const uint8_t* buffer, size_t buffer_size); void furi_hal_console_tx_with_new_line(const uint8_t* buffer, size_t buffer_size);