From 42cc656dbb08b89df2d919b3f2d060b0cd832f5b Mon Sep 17 00:00:00 2001 From: Winford Date: Sun, 20 Aug 2023 13:22:49 -0700 Subject: [PATCH 1/2] Support `long long` on stm32 The linker flag `-specs=nano.specs` has been removed by default to support the use of `long long` integers in `newlib`, and correct `printf` formatting. The `nano newlib` can still be used by passing `-DAVM_NEWLIB_NANO=on` to cmake when configuring the build. Signed-off-by: Winford --- doc/src/build-instructions.md | 2 ++ src/platforms/stm32/CMakeLists.txt | 5 +++++ src/platforms/stm32/cmake/libopencm3.cmake | 2 +- 3 files changed, 8 insertions(+), 1 deletion(-) diff --git a/doc/src/build-instructions.md b/doc/src/build-instructions.md index c148d9e46..7dcc3f90b 100644 --- a/doc/src/build-instructions.md +++ b/doc/src/build-instructions.md @@ -529,6 +529,8 @@ If you are building for a different target board the `CLOCK_FREQUENCY` definitio The rcc_clock_setup_XXX_XXX will also need to be changed to match your particular chip-set. Consult [ST's documentation](https://www.st.com/en/microcontrollers-microprocessors/stm32-32-bit-arm-cortex-mcus.html) for appropriate settings. ### Printing +AtomVM is built with standard `newlib` to support `long long` integers (`signed` and `unsigned`). If you are building for a device with extremely limited flash space the `nano` version of `newlib` can be used instead. This will save approximately 46kB of flash. This may be done by passing `-DAVM_NEWLIB_NANO=on`. + By default, stdout and stderr are printed on USART2. On the STM32F4Discovery board, you can see them using a TTL-USB with the TX pin connected to board's pin PA2 (USART2 RX). Baudrate is 115200 and serial transmission is 8N1 with no flow control. diff --git a/src/platforms/stm32/CMakeLists.txt b/src/platforms/stm32/CMakeLists.txt index d5bb2814b..67f815549 100644 --- a/src/platforms/stm32/CMakeLists.txt +++ b/src/platforms/stm32/CMakeLists.txt @@ -28,9 +28,14 @@ set(CMAKE_RUNTIME_OUTPUT_DIRECTORY ${CMAKE_BINARY_DIR}) option(AVM_USE_32BIT_FLOAT "Use 32 bit floats." OFF) option(AVM_VERBOSE_ABORT "Print module and line number on VM abort" OFF) option(AVM_CREATE_STACKTRACES "Create stacktraces" ON) +option(AVM_NEWLIB_NANO "Use 'nano' newlib. Saves 46kB, no `long long` support" OFF) set(AVM_DISABLE_SMP ON FORCE) +if (AVM_NEWLIB_NANO) + set(LINKER_FLAGS "${LINKER_FLAGS} -specs=nano.specs") +endif() + # Include an error in case the user forgets to specify ARM as a toolchain if (NOT CMAKE_TOOLCHAIN_FILE) message(FATAL_ERROR "Cross compiling only. Please use -DCMAKE_TOOLCHAIN_FILE=cmake/arm-toolchain.cmake or use\ diff --git a/src/platforms/stm32/cmake/libopencm3.cmake b/src/platforms/stm32/cmake/libopencm3.cmake index 9f026c34b..b4d3eb430 100644 --- a/src/platforms/stm32/cmake/libopencm3.cmake +++ b/src/platforms/stm32/cmake/libopencm3.cmake @@ -145,7 +145,7 @@ message(STATUS "Generated Linker File : ${CMAKE_CURRENT_BINARY_DIR}/${LINKER_S # ARCH_FLAGS has to be passed as a string here JOIN("${ARCH_FLAGS}" " " ARCH_FLAGS) # Set linker flags -set(LINKER_FLAGS "${LINKER_FLAGS} -specs=nosys.specs -specs=nano.specs -nostartfiles -Wl,--undefined,_printf_float -Wl,--undefined,_scanf_float -T${CMAKE_CURRENT_BINARY_DIR}/${LINKER_SCRIPT} ${ARCH_FLAGS}") +set(LINKER_FLAGS "${LINKER_FLAGS} -specs=nosys.specs -nostartfiles -Wl,--undefined,_printf_float -Wl,--undefined,_scanf_float -T${CMAKE_CURRENT_BINARY_DIR}/${LINKER_SCRIPT} ${ARCH_FLAGS}") message(STATUS "Linker Flags : ${LINKER_FLAGS}") # Compiler flags From 6062b0aae504ddc01fd428df14e2a154e7a249ed Mon Sep 17 00:00:00 2001 From: Winford Date: Sat, 12 Aug 2023 19:18:36 -0700 Subject: [PATCH 2/2] Improved logging on stm32 platform Introduces configureable logging with maximum log level, optional colorization by level, and optional source file and line numers with log messages (always on for `ERROR` messages), as described in stm32 section of `Build Instructions`. Signed-off-by: Winford --- CHANGELOG.md | 4 + doc/src/build-instructions.md | 16 ++- src/platforms/stm32/CMakeLists.txt | 25 ++++- src/platforms/stm32/src/lib/CMakeLists.txt | 2 + src/platforms/stm32/src/lib/avm_log.h | 112 +++++++++++++++++++++ src/platforms/stm32/src/lib/sys.c | 11 +- src/platforms/stm32/src/main.c | 46 +++++++-- 7 files changed, 200 insertions(+), 16 deletions(-) create mode 100644 src/platforms/stm32/src/lib/avm_log.h diff --git a/CHANGELOG.md b/CHANGELOG.md index c4a156e2b..fa82c18ea 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -6,6 +6,10 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ## [0.6.0-alpha.1] - Unreleased +### Added + +- Added configurable logging macros to stm32 platform + ### Fixed - Fixed `esp:nvs_set_binary` functions. diff --git a/doc/src/build-instructions.md b/doc/src/build-instructions.md index 7dcc3f90b..5fd291297 100644 --- a/doc/src/build-instructions.md +++ b/doc/src/build-instructions.md @@ -528,8 +528,22 @@ If you are building for a different target board the `CLOCK_FREQUENCY` definitio The rcc_clock_setup_XXX_XXX will also need to be changed to match your particular chip-set. Consult [ST's documentation](https://www.st.com/en/microcontrollers-microprocessors/stm32-32-bit-arm-cortex-mcus.html) for appropriate settings. +### Configure logging with `cmake` +The default maximum log level is `LOG_INFO`. To change the maximum level displayed pass `-DAVM_LOG_LEVEL_MAX="{level}"` to `cmake`, with one of `LOG_ERROR`, `LOG_WARN`, `LOG_INFO`, or `LOG_DEBUG` (listed from least to most verbose). Log messages can be completely disabled by using `-DAVM_LOG_DISABLE=on`. + +For log entries colorized by log level pass `-DAVM_ENABLE_LOG_COLOR=on` to cmake. With color enable there is a very small performance penalty (~1ms per message printed), the log entries are colored as follows: + +| Message Level | Color | +|---------------|---------| +| ERROR | Red | +| WARN | Orange | +| INFO | Green | +| DEBUG | Blue | + +By default only `ERROR` messages contain file and line number information. This can be included with all log entries by passing `-DAVM_ENABLE_LOG_LINES=on` to cmake, but it does incur a significant performance penalty and is only suggested for debugging during development. + ### Printing -AtomVM is built with standard `newlib` to support `long long` integers (`signed` and `unsigned`). If you are building for a device with extremely limited flash space the `nano` version of `newlib` can be used instead. This will save approximately 46kB of flash. This may be done by passing `-DAVM_NEWLIB_NANO=on`. +AtomVM is built with standard `newlib` to support `long long` integers (`signed` and `unsigned`). If you are building for a device with extremely limited flash space the `nano` version of `newlib` can be used instead. This may be done by passing `-DAVM_NEWLIB_NANO=on`. If the `nano newlib` is used logs will be automatically disabled, this is because many of the VM low level log messages will include `%ull` formatting and will cause buffer overflows and crash the VM if logging is not disabled for `nano newlib` builds. The total flash savings of using `nano newlib` and disabling logs is just under 40kB. By default, stdout and stderr are printed on USART2. On the STM32F4Discovery board, you can see them using a TTL-USB with the TX pin connected to board's pin PA2 (USART2 RX). Baudrate is 115200 and serial transmission diff --git a/src/platforms/stm32/CMakeLists.txt b/src/platforms/stm32/CMakeLists.txt index 67f815549..3232756a6 100644 --- a/src/platforms/stm32/CMakeLists.txt +++ b/src/platforms/stm32/CMakeLists.txt @@ -20,20 +20,43 @@ cmake_minimum_required (VERSION 3.13) project(AtomVM) + list(APPEND CMAKE_MODULE_PATH "${CMAKE_CURRENT_SOURCE_DIR}/../../../CMakeModules") set(CMAKE_RUNTIME_OUTPUT_DIRECTORY ${CMAKE_BINARY_DIR}) - # Options that make sense for this platform option(AVM_USE_32BIT_FLOAT "Use 32 bit floats." OFF) option(AVM_VERBOSE_ABORT "Print module and line number on VM abort" OFF) option(AVM_CREATE_STACKTRACES "Create stacktraces" ON) option(AVM_NEWLIB_NANO "Use 'nano' newlib. Saves 46kB, no `long long` support" OFF) +option(AVM_LOG_DISABLE "Disable log output" OFF) +option(AVM_ENABLE_LOG_COLOR "Use color log output" OFF) +option(AVM_ENABLE_LOG_LINES "Include source and line info for all enbled levels" OFF) set(AVM_DISABLE_SMP ON FORCE) if (AVM_NEWLIB_NANO) set(LINKER_FLAGS "${LINKER_FLAGS} -specs=nano.specs") + set(AVM_LOG_DISABLE ON FORCE) +endif() + +# Configure logging +if (AVM_LOG_DISABLE) + add_compile_definitions(AVM_LOG_DISABLE) +elseif (AVM_LOG_LEVEL_MAX) + set(CONFIG_LOG_LEVEL_MAX ${AVM_LOG_LEVEL_MAX} CACHE STRING "AtomVM max log level") +else() + set(CONFIG_LOG_LEVEL_MAX LOG_INFO CACHE STRING "AtomVM max log level") +endif() +if (CONFIG_LOG_LEVEL_MAX) + set_property(CACHE CONFIG_LOG_LEVEL_MAX PROPERTY STRINGS LOG_NONE LOG_ERROR LOG_WARN LOG_INFO LOG_DEBUG) + add_compile_definitions(CONFIG_LOG_LEVEL_MAX=${CONFIG_LOG_LEVEL_MAX}) +endif() +if (AVM_ENABLE_LOG_COLOR) + add_compile_definitions(ENABLE_LOG_COLOR) +endif() +if (AVM_ENABLE_LOG_LINES) + add_compile_definitions(ENABLE_LOG_LINE_INFO) endif() # Include an error in case the user forgets to specify ARM as a toolchain diff --git a/src/platforms/stm32/src/lib/CMakeLists.txt b/src/platforms/stm32/src/lib/CMakeLists.txt index 7488643a1..e9851cee0 100644 --- a/src/platforms/stm32/src/lib/CMakeLists.txt +++ b/src/platforms/stm32/src/lib/CMakeLists.txt @@ -24,6 +24,8 @@ project (libAtomVMPlatformSTM32) set(HEADER_FILES gpiodriver.h platform_defaultatoms.h + avm_log.h + ../../../../libAtomVM/sys.h ) set(SOURCE_FILES diff --git a/src/platforms/stm32/src/lib/avm_log.h b/src/platforms/stm32/src/lib/avm_log.h new file mode 100644 index 000000000..0363ae91d --- /dev/null +++ b/src/platforms/stm32/src/lib/avm_log.h @@ -0,0 +1,112 @@ +/* This file is part of AtomVM. + * + * Copyright 2023 Winford (Uncle Grumpy) + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + * + * SPDX-License-Identifier: Apache-2.0 OR LGPL-2.1-or-later + */ + +#ifndef _AVM_LOG_H_ +#define _AVM_LOG_H_ + +#include +#include + +#include + +enum AVMLogLevel +{ + LOG_NONE = 0, + LOG_ERROR, + LOG_WARN, + LOG_INFO, + LOG_DEBUG +}; + +#ifndef AVM_LOG_DISABLE + +#ifdef CONFIG_LOG_LEVEL_MAX +#define LOG_LEVEL_MAX CONFIG_LOG_LEVEL_MAX +#else +#define LOG_LEVEL_MAX LOG_INFO +#endif + +/* clang-format off */ +#ifdef ENABLE_LOG_COLOR +// #define LOG_COLOR_BLACK "\033[0;30m" +// #define LOG_COLOR_GREY "\033[1;30m" +// #define LOG_COLOR_RED "\033[0;31m" +// #define LOG_BOLD_RED "\033[1;31m" +// #define LOG_COLOR_GREEN "\033[0;32m" +// #define LOG_COLOR_ALIEN "\033[1;32m" +// #define LOG_COLOR_ORANGE "\033[0;33m" +// #define LOG_COLOR_YELLOW "\033[1;33m" +// #define LOG_COLOR_BLUE "\033[0;34m" +// #define LOG_COLOR_PURPLE "\033[0;35m" +// #define LOG_COLOR_PINK "\033[1;35m" +// #define LOG_COLOR_CYAN "\033[0;36m" +#define LOG_COLOR_ERROR "\033[1;31m" +#define LOG_COLOR_WARN "\033[0;33m" +#define LOG_COLOR_INFO "\033[0;32m" +#define LOG_COLOR_DEBUG "\033[0;34m" +#define LOG_RESET_COLOR "\033[0m" +#else /* ENABLE_LOG_COLOR OFF */ +#define LOG_COLOR_ERROR +#define LOG_COLOR_WARN +#define LOG_COLOR_INFO +#define LOG_COLOR_DEBUG +#define LOG_RESET_COLOR +#endif /* ENABLE_LOG_COLOR */ + +#ifdef ENABLE_LOG_LINE_INFO +#define LINE_FORMAT " (%s:%i)" +#define LINE_DATA , __FILE__, __LINE__ +#else /* ENABLE_LOG_LINE_INFO OFF*/ +#define LINE_FORMAT +#define LINE_DATA +#endif /* ENABLE_LOG_LINE_INFO */ +/* clang-format on */ + +#define AVM_LOGE(tag, format, ...) \ + do { \ + uint64_t logtime = sys_monotonic_millis(); \ + if (LOG_LEVEL_MAX >= LOG_ERROR) \ + printf(LOG_COLOR_ERROR "ERROR [%llu] %s: " format " (%s:%i)" LOG_RESET_COLOR "\n", logtime, tag, ##__VA_ARGS__, __FILE__, __LINE__); \ + } while (0) +#define AVM_LOGW(tag, format, ...) \ + do { \ + uint64_t logtime = sys_monotonic_millis(); \ + if (LOG_LEVEL_MAX >= LOG_WARN) \ + printf(LOG_COLOR_WARN "WARN [%llu] %s: " format LINE_FORMAT LOG_RESET_COLOR "\n", logtime, tag, ##__VA_ARGS__ LINE_DATA); \ + } while (0) +#define AVM_LOGI(tag, format, ...) \ + do { \ + uint64_t logtime = sys_monotonic_millis(); \ + if (LOG_LEVEL_MAX >= LOG_INFO) \ + printf(LOG_COLOR_INFO "INFO [%llu] %s: " format LINE_FORMAT LOG_RESET_COLOR "\n", logtime, tag, ##__VA_ARGS__ LINE_DATA); \ + } while (0) +#define AVM_LOGD(tag, format, ...) \ + do { \ + uint64_t logtime = sys_monotonic_millis(); \ + if (LOG_LEVEL_MAX >= LOG_DEBUG) \ + printf(LOG_COLOR_DEBUG "DEBUG [%llu] %s: " format LINE_FORMAT LOG_RESET_COLOR "\n", logtime, tag, ##__VA_ARGS__ LINE_DATA); \ + } while (0) +#else +#define AVM_LOGE(tag, format, ...) +#define AVM_LOGW(tag, format, ...) +#define AVM_LOGI(tag, format, ...) +#define AVM_LOGD(tag, format, ...) +#endif /* AVM_LOG_DISABLE */ + +#endif /* _AVM_LOG_H_ */ diff --git a/src/platforms/stm32/src/lib/sys.c b/src/platforms/stm32/src/lib/sys.c index 4951be05e..6a2f25019 100644 --- a/src/platforms/stm32/src/lib/sys.c +++ b/src/platforms/stm32/src/lib/sys.c @@ -18,15 +18,17 @@ * SPDX-License-Identifier: Apache-2.0 OR LGPL-2.1-or-later */ -#include - #include #include #include +#include + +#include +#include "avm_log.h" #include "gpiodriver.h" -#include "trace.h" +#define TAG "sys" void sys_tick_handler(); @@ -107,6 +109,7 @@ enum OpenAVMResult sys_open_avm_from_file( TRACE("sys_open_avm_from_file: Going to open: %s\n", path); // TODO + AVM_LOGW(TAG, "Open from file not supported on this platform."); return AVM_OPEN_NOT_SUPPORTED; } @@ -133,7 +136,7 @@ Module *sys_load_module(GlobalContext *global, const char *module_name) synclist_unlock(&global->avmpack_data); if (IS_NULL_PTR(beam_module)) { - fprintf(stderr, "Failed to open module: %s\n", module_name); + AVM_LOGE(TAG, "Failed to open module: %s.", module_name); return NULL; } diff --git a/src/platforms/stm32/src/main.c b/src/platforms/stm32/src/main.c index 1b55f2785..3dc600da3 100644 --- a/src/platforms/stm32/src/main.c +++ b/src/platforms/stm32/src/main.c @@ -19,24 +19,46 @@ */ #include +#include +#include + #include #include #include #include #include -#include -#include #include #include #include #include +#include +#include + +#include "lib/avm_log.h" #define USART_CONSOLE USART2 #define AVM_ADDRESS (0x8080000) #define AVM_FLASH_MAX_SIZE (0x80000) #define CLOCK_FREQUENCY (168000000) +#define TAG "AtomVM" + +#define ATOMVM_BANNER \ + "\n" \ + " ###########################################################\n" \ + "\n" \ + " ### ######## ####### ## ## ## ## ## ## \n" \ + " ## ## ## ## ## ### ### ## ## ### ### \n" \ + " ## ## ## ## ## #### #### ## ## #### #### \n" \ + " ## ## ## ## ## ## ### ## ## ## ## ### ## \n" \ + " ######### ## ## ## ## ## ## ## ## ## \n" \ + " ## ## ## ## ## ## ## ## ## ## ## \n" \ + " ## ## ## ####### ## ## ### ## ## \n" \ + "\n" \ + " ###########################################################\n" \ + "\n" + int _write(int file, char *ptr, int len); static void clock_setup() @@ -106,6 +128,10 @@ int main() systick_setup(); usart_setup(); + fprintf(stdout, "%s", ATOMVM_BANNER); + AVM_LOGI(TAG, "Starting AtomVM revision " ATOMVM_VERSION); + AVM_LOGD(TAG, "Using usart mapped at register 0x%x for stdout/stderr.", USART_CONSOLE); + const void *flashed_avm = (void *) AVM_ADDRESS; uint32_t size = AVM_FLASH_MAX_SIZE; @@ -113,19 +139,20 @@ int main() const void *startup_beam; const char *startup_module_name; - printf("Booting file mapped at: %p, size: %li\n", flashed_avm, size); + AVM_LOGD(TAG, "Maximum application size: %lu", size); GlobalContext *glb = globalcontext_new(); if (!avmpack_is_valid(flashed_avm, size) || !avmpack_find_section_by_flag(flashed_avm, BEAM_START_FLAG, &startup_beam, &startup_beam_size, &startup_module_name)) { - fprintf(stderr, "error: invalid AVM Pack\n"); - return 1; + AVM_LOGE(TAG, "Invalid AVM Pack"); + AVM_ABORT(); } + AVM_LOGI(TAG, "Booting file mapped at: %p, size: %lu", flashed_avm, startup_beam_size); struct ConstAVMPack *avmpack_data = malloc(sizeof(struct ConstAVMPack)); if (IS_NULL_PTR(avmpack_data)) { - fprintf(stderr, "Memory error: Cannot allocate AVMPackData.\n"); - return 1; + AVM_LOGE(TAG, "Memory error: Cannot allocate AVMPackData."); + AVM_ABORT(); } avmpack_data_init(&avmpack_data->base, &const_avm_pack_info); avmpack_data->base.data = flashed_avm; @@ -136,10 +163,9 @@ int main() globalcontext_insert_module(glb, mod); Context *ctx = context_new(glb); - printf("Starting: %s...\n", startup_module_name); - printf("---\n"); + AVM_LOGI(TAG, "Starting: %s...\n", startup_module_name); context_execute_loop(ctx, mod, "start", 0); - printf("Return value: %lx\n", (long) term_to_int32(ctx->x[0])); + AVM_LOGI(TAG, "Return value: %lx", (long) term_to_int32(ctx->x[0])); while (1) ;