Memfault Firmware SDK 1.17.0 (Build 11353)

CHANGELOG.md

@@ -6,6 +6,97 @@ The format is based on [Keep a Changelog](https://keepachangelog.com/en/1.0.0/),
 and this project adheres to
 [Semantic Versioning](https://semver.org/spec/v2.0.0.html).
 
+## [1.17.0] - 2024-11-14
+
+### 📈 Added
+
+- General:
+
+  - Add parsing of an optional log message argument for the `test_trace` command
+    in the [core demo cli](components/demo). This argument will be inserted as a
+    custom log message with the trace event, which can be useful for testing the
+    insertion of custom log messages into trace events at runtime.
+
+  - Add the following built-in metrics, enabled by default (and quota-exempt):
+
+    - `MemfaultSDKMetric_log_recorded_lines` : the total number of log lines
+      written into the Memfault log buffer during the heartbeat interval
+    - `MemfaultSDKMetric_log_dropped_lines` : the total number of log lines
+      dropped (overwritten or not recorded) due to buffer exhaustion during the
+      heartbeat interval
+
+    For example, if the buffer is sufficiently large to store 10 logs, and 15
+    logs are written:
+
+    - `MemfaultSDKMetric_log_recorded_lines` will be 15
+    - `MemfaultSDKMetric_log_dropped_lines` will be 5
+
+    If 5 more logs are written:
+
+    - `MemfaultSDKMetric_log_recorded_lines` will be 20
+    - `MemfaultSDKMetric_log_dropped_lines` will be 10
+
+  - Cosmetic updates to the `examples/freertos/` app log format, including
+    applying ANSI color codes based on log level.
+
+    ```bash
+    # Before:
+    mflt> test_log
+    Raw log!
+    2024-11-14T17:01:12Z|4284 I Info log!
+    2024-11-14T17:01:12Z|4284 W Warning log!
+    2024-11-14T17:01:12Z|4284 E Error log!
+
+    # After:
+    mflt> test_log
+    Raw log!
+    MFLT:[INFO] Info log!
+    MFLT:[WARN] Warning log!
+    MFLT:[ERRO] Error log!
+    ```
+
+- ESP-IDF:
+
+  - Enable NTP time synchronization by default, controlled with the Kconfig
+    option `CONFIG_MEMFAULT_NTP_SYNC`. After NTP synchronization, events
+    (heartbeats and trace events) will be timestamped with the current device
+    time.
+
+  - Add a `test_trace` command to the ESP-IDF demo cli to capture an example
+    trace event. This behaves the same as the `test_trace` command in the
+    [core demo cli](components/demo).
+  - Mark coredumps with the `Software Watchdog` crash reason if the IWDT
+    triggered the fault, instead of marking them as `Hard Fault`.
+
+  - Add OTA update check-ins to the HTTP client's periodic upload, controlled
+    with the Kconfig option `CONFIG_MEMFAULT_HTTP_PERIODIC_UPLOAD_OTA`. When
+    enabled, the system will be restarted after downloading the update. To
+    customize this behavior, enable
+    `CONFIG_MEMFAULT_HTTP_PERIODIC_UPLOAD_OTA_CUSTOM_CBS`, and implement the
+    global callback struct `g_memfault_ota_update_handler`. This feature is
+    disabled by default.
+
+### 🐛 Fixed
+
+- General:
+
+  - Add missing type promotion rules for variants of `char` pointers when
+    encoding compact logs. Previously, these types that should promote to a
+    string in the compact logging encoding fell into the default case of `int`,
+    causing compact logging decode to fail when processed by the Memfault
+    backend.
+
+- ESP-IDF:
+
+  - Fix an issue when using compact logs with
+    `CONFIG_MEMFAULT_USE_MEMFAULT_BUILD_ID=y` (default). The command would
+    always run (was always out-of-date) when any `idf.py [build|flash]` command
+    is run, even if the original .elf file did not change. This caused the
+    `log_fmt` section (used for decoding compact logs) to be removed from the
+    `/memfault-esp32-demo-app.elf.memfault_log_fmt` file, which causes Memfault
+    Compact Logs to fail to decode. The command is fixed to only run when the
+    .elf file changes.
+
 ## [1.16.0] - 2024-10-24
 
 ### 🔥 Removed
@@ -58,12 +149,18 @@ earlier versions!
     `memfault_reboot_tracking_load()` / `memfault_reboot_tracking_save()`
     functions to demonstrate the functionality.
 
+  - Added a Kconfig flag, `CONFIG_MEMFAULT_METRICS_LOGS_ENABLE`, to control the
+    new log lines metrics.
+
 - ESP-IDF:
 
   - New Kconfig setting, `CONFIG_MEMFAULT_ENABLE_REBOOT_DIAG_DUMP`, to print the
     ESP-IDF reboot reason code on system boot, for debugging purposes. This
     feature is disabled by default.
 
+  - Added a Kconfig flag, `CONFIG_MEMFAULT_METRICS_LOGS_ENABLE`, to control the
+    new log lines metrics.
+
 ### 🛠️ Changed
 
 - General:

VERSION

@@ -1,3 +1,3 @@
-BUILD ID: 10952
-GIT COMMIT: c690f5abc6
-VERSION: 1.16.0
+BUILD ID: 11353
+GIT COMMIT: 767ed66f9e
+VERSION: 1.17.0

components/core/src/memfault_log.c

@@ -46,10 +46,11 @@ typedef struct {
   // Can be changed with memfault_log_set_min_save_level()
   eMemfaultPlatformLogLevel min_log_level;
   uint32_t log_read_offset;
-  // The number of messages that were flushed without ever being read. If memfault_log_read() is
-  // not used by a platform, this will be equivalent to the number of messages logged since boot
-  // that are no longer in the log buffer.
+  // The total number of messages that were not recorded into the buffer, either
+  // due to lack of space, or if the buffer was locked by the data source.
   uint32_t dropped_msg_count;
+  // The total number of messages that were recorded into the buffer
+  uint32_t recorded_msg_count;
   sMfltCircularBuffer circ_buffer;
   // When initialized we keep track of the user provided storage buffer and crc the location +
   // size. When the system crashes we can check to see if this info has been corrupted in any way
@@ -67,6 +68,14 @@ static uint16_t prv_compute_log_region_crc16(void) {
                                       offsetof(sMfltLogStorageRegionInfo, crc16));
 }
 
+uint32_t memfault_log_get_dropped_count(void) {
+  return s_memfault_ram_logger.dropped_msg_count;
+}
+
+uint32_t memfault_log_get_recorded_count(void) {
+  return s_memfault_ram_logger.recorded_msg_count;
+}
+
 bool memfault_log_get_regions(sMemfaultLogRegions *regions) {
   if (!s_memfault_ram_logger.enabled) {
     return false;
@@ -129,11 +138,17 @@ static bool prv_try_free_space(sMfltCircularBuffer *circ_bufp, int bytes_needed)
 
   // Expire oldest logs until there is enough room available
   while (tot_read_space != 0) {
+    // Log lines are stored as 2 entries in the circular buffer:
+    // 1. sMfltRamLogEntry header
+    // 2. log message (compact or formatted)
+    // When freeing space, clear both the header and the message
     sMfltRamLogEntry curr_entry = { 0 };
     memfault_circular_buffer_read(circ_bufp, 0, &curr_entry, sizeof(curr_entry));
     const size_t space_to_free = curr_entry.len + sizeof(curr_entry);
 
-    if ((curr_entry.hdr & MEMFAULT_LOG_HDR_READ_MASK) != 0) {
+    if ((curr_entry.hdr & (MEMFAULT_LOG_HDR_READ_MASK | MEMFAULT_LOG_HDR_SENT_MASK)) != 0) {
+      // note: log_read_offset can safely wrap around, circular buffer API
+      // handles the modulo arithmetic
       s_memfault_ram_logger.log_read_offset -= space_to_free;
     } else {
       // We are removing a message that was not read via memfault_log_read().
@@ -220,14 +235,18 @@ static bool prv_read_log_iter_callback(sMfltLogIterator *iter) {
 }
 
 static bool prv_read_log(sMemfaultLog *log) {
-  if (s_memfault_ram_logger.dropped_msg_count) {
-    log->level = kMemfaultPlatformLogLevel_Warning;
-    const int rv = snprintf(log->msg, sizeof(log->msg), "... %d messages dropped ...",
-                            (int)s_memfault_ram_logger.dropped_msg_count);
-    log->msg_len = (rv <= 0) ? 0 : MEMFAULT_MIN((uint32_t)rv, sizeof(log->msg) - 1);
-    log->type = kMemfaultLogRecordType_Preformatted;
-    s_memfault_ram_logger.dropped_msg_count = 0;
-    return true;
+  static uint32_t s_last_dropped_count = 0;
+
+  if (s_last_dropped_count != s_memfault_ram_logger.dropped_msg_count) {
+    s_last_dropped_count = s_memfault_ram_logger.dropped_msg_count;
+    if (s_last_dropped_count > 0) {
+      log->level = kMemfaultPlatformLogLevel_Warning;
+      const int rv = snprintf(log->msg, sizeof(log->msg), "... %d messages dropped ...",
+                              (int)s_memfault_ram_logger.dropped_msg_count);
+      log->msg_len = (rv <= 0) ? 0 : MEMFAULT_MIN((uint32_t)rv, sizeof(log->msg) - 1);
+      log->type = kMemfaultLogRecordType_Preformatted;
+      return true;
+    }
   }
 
   sMfltReadLogCtx user_ctx = { .log = log };
@@ -393,13 +412,16 @@ static void prv_log_save(eMemfaultPlatformLogLevel level, const void *log, size_
     sMfltCircularBuffer *circ_bufp = &s_memfault_ram_logger.circ_buffer;
     const bool space_free = prv_try_free_space(circ_bufp, (int)bytes_needed);
     if (space_free) {
+      s_memfault_ram_logger.recorded_msg_count++;
       sMfltRamLogEntry entry = {
         .len = (uint8_t)truncated_log_len,
         .hdr = prv_build_header(level, log_type),
       };
       memfault_circular_buffer_write(circ_bufp, &entry, sizeof(entry));
       memfault_circular_buffer_write(circ_bufp, log, truncated_log_len);
       log_written = true;
+    } else {
+      s_memfault_ram_logger.dropped_msg_count++;
     }
   }
   if (should_lock) {

components/core/src/memfault_self_test.c

@@ -352,31 +352,31 @@ MEMFAULT_NO_OPT static uint32_t prv_get_time_since_boot_test(void) {
   #define MEMFAULT_SELF_TEST_TIMESTAMP_ANCHOR (1706486400)
 
 static uint32_t prv_platform_time_get_current_test(void) {
-  sMemfaultCurrentTime time = {
+  sMemfaultCurrentTime mflt_time = {
     .type = kMemfaultCurrentTimeType_Unknown,
     .info = {
       .unix_timestamp_secs = 0,
     },
   };
-  bool result = memfault_platform_time_get_current(&time);
+  bool result = memfault_platform_time_get_current(&mflt_time);
   if (!result) {
     MEMFAULT_LOG_ERROR("Current timestamp could not be recovered");
     return (1 << 2);
   }
 
-  if (time.type != kMemfaultCurrentTimeType_UnixEpochTimeSec) {
-    MEMFAULT_LOG_ERROR("Invalid time type returned: %u", time.type);
+  if (mflt_time.type != kMemfaultCurrentTimeType_UnixEpochTimeSec) {
+    MEMFAULT_LOG_ERROR("Invalid time type returned: %u", mflt_time.type);
     return (1 << 3);
   }
 
-  if (time.info.unix_timestamp_secs < MEMFAULT_SELF_TEST_TIMESTAMP_ANCHOR) {
+  if (mflt_time.info.unix_timestamp_secs < MEMFAULT_SELF_TEST_TIMESTAMP_ANCHOR) {
     MEMFAULT_LOG_ERROR("Timestamp too far in the past: %" PRIu32,
-                       (uint32_t)time.info.unix_timestamp_secs);
+                       (uint32_t)mflt_time.info.unix_timestamp_secs);
     return (1 << 4);
   }
 
   MEMFAULT_LOG_INFO("Verify received timestamp for accuracy. Timestamp received %" PRIu32,
-                    (uint32_t)time.info.unix_timestamp_secs);
+                    (uint32_t)mflt_time.info.unix_timestamp_secs);
   return 0;
 }
 

components/demo/src/memfault_demo_cli_trace_event.c

@@ -7,14 +7,16 @@
 //! CLI command that exercises the MEMFAULT_TRACE_EVENT API, capturing a
 //! Trace Event with the error reason set to "MemfaultDemoCli_Error".
 
-#include "memfault/core/compiler.h"
-#include "memfault/core/debug_log.h"
 #include "memfault/core/trace_event.h"
 #include "memfault/demo/cli.h"
 
-int memfault_demo_cli_cmd_trace_event_capture(int argc, MEMFAULT_UNUSED char *argv[]) {
+int memfault_demo_cli_cmd_trace_event_capture(int argc, char *argv[]) {
   // For more information on user-defined error reasons, see
   // the MEMFAULT_TRACE_REASON_DEFINE macro in trace_reason_user.h .
-  MEMFAULT_TRACE_EVENT_WITH_LOG(MemfaultCli_Test, "Example Trace Event. Num Args %d", argc);
+  if (argc < 2) {
+    MEMFAULT_TRACE_EVENT_WITH_LOG(MemfaultCli_Test, "Example Trace Event. Num Args %d", argc);
+  } else {
+    MEMFAULT_TRACE_EVENT_WITH_LOG(MemfaultCli_Test, "%s", argv[1]);
+  }
   return 0;
 }

components/include/memfault/core/compact_log_helpers.h

@@ -39,11 +39,38 @@
 
   #ifdef __cplusplus
 
-  // C++ implementation of the type promotion logic
-  //
-  // Note: the C++ implementation requires the use of C++11 features and the GNU
-  // "##" variadic arg extension. Memfault Compact Logs in C++ require the
-  // compiler flag '--std=gnu++-11' or newer.
+  //! C++ type promotion logic
+  //!
+  //! This code defines the MemfaultLogArgPromotionType template structure, responsible for
+  //! determining the promotion type of different argument types passed to Memfault's logging
+  //! functions. This is important because certain types may need to be promoted to larger or
+  //! different types, ensuring consistent handling in logging The code uses C++11 features,
+  //! including SFINAE (Substitution Failure Is Not An Error) with std::enable_if, and the GNU ## va
+  //! args extension. It assumes the --std=gnu++11 compiler flag or newer.
+  //!
+  //! Structure definition:
+  //! 1. Default promotion to int64:
+  //!    - By default, if no other promotion rule applies, MemfaultLogArgPromotionType promotes the
+  //!    type to
+  //!      MEMFAULT_LOG_ARG_PROMOTED_TO_INT64, indicating that any unhandled type defaults to a
+  //!      64-bit integer.
+  //!
+  //! 2. Conditional promotion to int32:
+  //!    - If the size of the type T is less than or equal to 4 bytes (e.g., smaller integer types),
+  //!      MemfaultLogArgPromotionType promotes the type to MEMFAULT_LOG_ARG_PROMOTED_TO_INT32,
+  //!      allowing consistent handling for smaller integers.
+  //!
+  //! 3. Specialized promotions:
+  //!    - Specific types receive unique promotion constants:
+  //!      - Floating-point types (float, double, long double): Promoted to
+  //!      MEMFAULT_LOG_ARG_PROMOTED_TO_DOUBLE.
+  //!      - String types (char* variants): Promoted to MEMFAULT_LOG_ARG_PROMOTED_TO_STR.
+  //!
+  //! Macro definition:
+  //! - _MEMFAULT_LOG_ARG_PROMOTION_TYPE(arg): This macro determines the promotion type of an
+  //! argument.
+  //!   The (arg) + 0 operation is used to enforce integer promotion for non-integer types, helping
+  //!   the compiler resolve the appropriate type for MemfaultLogArgPromotionType.
 
     #include <type_traits>
 
@@ -78,22 +105,43 @@ template <>
 struct MemfaultLogArgPromotionType<const char *>
     : std::integral_constant<int, MEMFAULT_LOG_ARG_PROMOTED_TO_STR> { };
 
-    // When expressing the final type via the template parameter expansion, operate
-    // on (arg) + 0 to force integer promotion
+template <>
+struct MemfaultLogArgPromotionType<signed char *>
+    : std::integral_constant<int, MEMFAULT_LOG_ARG_PROMOTED_TO_STR> { };
+
+template <>
+struct MemfaultLogArgPromotionType<const signed char *>
+    : std::integral_constant<int, MEMFAULT_LOG_ARG_PROMOTED_TO_STR> { };
+
+template <>
+struct MemfaultLogArgPromotionType<unsigned char *>
+    : std::integral_constant<int, MEMFAULT_LOG_ARG_PROMOTED_TO_STR> { };
+
+template <>
+struct MemfaultLogArgPromotionType<const unsigned char *>
+    : std::integral_constant<int, MEMFAULT_LOG_ARG_PROMOTED_TO_STR> { };
+
     #define _MEMFAULT_LOG_ARG_PROMOTION_TYPE(arg) \
       MemfaultLogArgPromotionType<decltype((arg) + 0)>::value
 
   #else  // C Code implementation
 
-  //! Preprocessor macro to encode promotion type info about each va_arg in a uint32_t
+  //! C type promotion logic
   //!
   //! Utilizes the rules around "default argument promotion" (specifically for va_args) defined in
   //! the C specification (http://www.iso-9899.info/wiki/The_Standard) to encode information about
   //! the width of arguments. (For more details see "6.5.2.2 Function calls" in the C11 Spec).
   //!
-  //! In short,
-  //!  - floats are always promoted to doubles
-  //!  - any other type < sizeof(int) is promoted to the width of an int
+  //! Promotion Rules:
+  //!  - Floating-point types (float, double, long double): Promoted to
+  //!  MEMFAULT_LOG_ARG_PROMOTED_TO_DOUBLE.
+  //!  - String types (char* variants): Promoted to MEMFAULT_LOG_ARG_PROMOTED_TO_STR.
+  //!  - Default case:
+  //!   - If the size of the argument is less than or equal to the size of an int, the type is
+  //!   promoted to
+  //!     MEMFAULT_LOG_ARG_PROMOTED_TO_INT32.
+  //!   - Otherwise, it defaults to MEMFAULT_LOG_ARG_PROMOTED_TO_INT64, for larger integer types.
+  //!   - Notably, bool and _BitInt(N) are safely promoted to int by falling into this case.
   //!
   //! NOTE 1: We use a special type for "strings" (i.e char *) so we know to encode the value
   //! pointed to (the actual NUL terminated string) in this situation rather than the pointer
@@ -118,15 +166,19 @@ struct MemfaultLogArgPromotionType<const char *>
 
   // clang-format off
 
-#define _MEMFAULT_LOG_ARG_PROMOTION_TYPE(arg)                           \
-  _Generic((arg) + 0,                                                   \
-           float:  MEMFAULT_LOG_ARG_PROMOTED_TO_DOUBLE,                 \
-           double:  MEMFAULT_LOG_ARG_PROMOTED_TO_DOUBLE,                \
-           long double:  MEMFAULT_LOG_ARG_PROMOTED_TO_DOUBLE,           \
-           char*:  MEMFAULT_LOG_ARG_PROMOTED_TO_STR,                    \
-           const char*:  MEMFAULT_LOG_ARG_PROMOTED_TO_STR,              \
-           default: sizeof((arg) + 0) <= sizeof(int) ?                  \
-              MEMFAULT_LOG_ARG_PROMOTED_TO_INT32 : MEMFAULT_LOG_ARG_PROMOTED_TO_INT64)
+    #define _MEMFAULT_LOG_ARG_PROMOTION_TYPE(arg)                          \
+      _Generic((arg) + 0,                                                  \
+              float:  MEMFAULT_LOG_ARG_PROMOTED_TO_DOUBLE,                 \
+              double:  MEMFAULT_LOG_ARG_PROMOTED_TO_DOUBLE,                \
+              long double:  MEMFAULT_LOG_ARG_PROMOTED_TO_DOUBLE,           \
+              char*:  MEMFAULT_LOG_ARG_PROMOTED_TO_STR,                    \
+              const char*:  MEMFAULT_LOG_ARG_PROMOTED_TO_STR,              \
+              signed char*:  MEMFAULT_LOG_ARG_PROMOTED_TO_STR,             \
+              const signed char*:  MEMFAULT_LOG_ARG_PROMOTED_TO_STR,       \
+              unsigned char*:  MEMFAULT_LOG_ARG_PROMOTED_TO_STR,           \
+              const unsigned char*:  MEMFAULT_LOG_ARG_PROMOTED_TO_STR,     \
+              default: sizeof((arg) + 0) <= sizeof(int) ?                  \
+                  MEMFAULT_LOG_ARG_PROMOTED_TO_INT32 : MEMFAULT_LOG_ARG_PROMOTED_TO_INT64)
 
   // clang-format on