From 001e8d1963af9b620a1e9318535530b8e63c39e7 Mon Sep 17 00:00:00 2001 From: SoWizard Date: Fri, 2 Oct 2026 17:56:33 +1000 Subject: [PATCH] Logging: handle allocation failures without null writes (#25094) --- tasmota/tasmota_support/support.ino | 4 +- .../xdrv_52_0_berry_struct.ino | 9 +- tests/test_logging_allocations.py | 230 ++++++++++++++++++ 3 files changed, 240 insertions(+), 3 deletions(-) create mode 100644 tests/test_logging_allocations.py diff --git a/tasmota/tasmota_support/support.ino b/tasmota/tasmota_support/support.ino index a9b17e668..d2807860a 100644 --- a/tasmota/tasmota_support/support.ino +++ b/tasmota/tasmota_support/support.ino @@ -2853,8 +2853,10 @@ void AddLogData(uint32_t loglevel, const char* log_data, const char* log_data_pa uint32_t log_data_len = strlen(log_data) + strlen(log_data_payload) + strlen(log_data_retained); if (log_data_len > MAX_LOGSZ) { too_long = (char*)malloc(TOPSZ); // Use heap in favour of stack + if (too_long == nullptr) { return; } // Drop the log without touching the existing buffer. snprintf_P(too_long, TOPSZ - 20, PSTR("%s%s"), log_data, log_data_payload); // 20 = strlen("... 123456 truncated") - snprintf_P(too_long, TOPSZ, PSTR("%s... %d truncated"), too_long, log_data_len); + size_t prefix_len = strlen(too_long); + snprintf_P(too_long + prefix_len, TOPSZ - prefix_len, PSTR("... %d truncated"), log_data_len); log_data = too_long; log_data_payload = empty; log_data_retained = empty; diff --git a/tasmota/tasmota_xdrv_driver/xdrv_52_0_berry_struct.ino b/tasmota/tasmota_xdrv_driver/xdrv_52_0_berry_struct.ino index 907714fbf..e5352ae6b 100644 --- a/tasmota/tasmota_xdrv_driver/xdrv_52_0_berry_struct.ino +++ b/tasmota/tasmota_xdrv_driver/xdrv_52_0_berry_struct.ino @@ -22,6 +22,7 @@ #include #include +#include #include "be_mapping.h" #include "re1.5.h" @@ -69,8 +70,12 @@ public: if (s == nullptr) { s = ""; } size_t s_len = strlen_P(s) + strlen_P(prefix) + strlen_P(suffix); if (0 == s_len) { return nullptr; } // do nothing - LList_elt * log_elt = new LList_elt(); - log_elt->val().allocate(s_len + 1); + LList_elt * log_elt = new (std::nothrow) LList_elt(); + if (log_elt == nullptr) { return nullptr; } + if (log_elt->val().allocate(s_len + 1) == nullptr) { + delete log_elt; + return nullptr; // Drop the log when its buffer cannot be allocated. + } snprintf_P(log_elt->val().getBuffer(), s_len+1, PSTR("%s%s%s"), prefix, s, suffix); log.addToLast(log_elt); return log_elt; diff --git a/tests/test_logging_allocations.py b/tests/test_logging_allocations.py new file mode 100644 index 000000000..50b94ddcd --- /dev/null +++ b/tests/test_logging_allocations.py @@ -0,0 +1,230 @@ +#!/usr/bin/env python3 +"""Fault-inject the actual firmware logging code without running a device. + +Run: python3 tests/test_logging_allocations.py [--check-baseline GIT_REF] +The optional baseline check requires both original paths to attempt a NULL write. +Only the platform services are stubbed; the logging code and LList are extracted +from the selected source tree. Generated C++ and binaries stay in a temp folder. +""" + +import argparse +import os +from pathlib import Path +import subprocess +import tempfile + +ROOT = Path(__file__).resolve().parents[1] +BERRY = 'tasmota/tasmota_xdrv_driver/xdrv_52_0_berry_struct.ino' +SUPPORT = 'tasmota/tasmota_support/support.ino' + +PRELUDE = r''' +#include +#include +#include +#include +#include +#include +#include +#include "LList.h" + +static bool fail_node, fail_berry, fail_log; +static void *node; +static unsigned berry_buffers, log_buffers, format_calls; +void *operator new(std::size_t size, const std::nothrow_t&) noexcept { + if (fail_node) return nullptr; + void *ptr = std::malloc(size); + assert(node == nullptr); + node = ptr; + return ptr; +} +void operator delete(void *ptr) noexcept { + if (ptr == node) node = nullptr; + std::free(ptr); +} +void *berry_malloc(size_t size) { + if (fail_berry) return nullptr; + void *ptr = std::malloc(size); + if (ptr) ++berry_buffers; + return ptr; +} +void berry_free(void *ptr) { + assert(ptr && berry_buffers); + --berry_buffers; + std::free(ptr); +} +void *log_malloc(size_t size) { + if (fail_log) return nullptr; + void *ptr = std::malloc(size); + if (ptr) ++log_buffers; + return ptr; +} +void log_free(void *ptr) { + assert(ptr && log_buffers); + --log_buffers; + std::free(ptr); +} +int checked_snprintf(char *dst, size_t size, const char *fmt, ...) { + ++format_calls; + if (!dst && size) { + std::fputs("NULL destination passed to snprintf\n", stderr); + std::exit(86); // Deterministic fault instead of invoking host undefined behavior. + } + va_list args; + va_start(args, fmt); + int result = std::vsnprintf(dst, size, fmt, args); + va_end(args); + return result; +} +#define snprintf_P checked_snprintf +#define strlen_P std::strlen +#define PSTR(s) s +#define D_HOUR_MINUTE_SEPARATOR ":" +#define D_MINUTE_SECOND_SEPARATOR ":" +#define LOG_BUFFER_SIZE 512 +#define MAX_LOGSZ (LOG_BUFFER_SIZE - 64) +#define TOPSZ 256 +struct { + unsigned maxlog_level = 2, seriallog_level = 0, masterlog_level = 0; + char *log_buffer = nullptr; + unsigned log_buffer_pointer = 1; +} TasmotaGlobal; +struct SettingsMock { + struct { bool show_heap_with_timestamp = false; } flag5; + struct { bool json_pretty_print = false; } mbflag2; +} settings; +SettingsMock *Settings = &settings; +struct { int hour = 1, minute = 2, second = 3; } RtcTime; +int RtcMillis() { return 4; } +int ESP_getFreeHeap1024() { return 100; } +int ESP_getHeapFragmentation() { return 0; } +unsigned HighestLogLevel() { return 2; } +struct Console { template void printf(Args...) {} } TasConsole; +void TasConsoleLDJsonPPCb(const char*, uint32_t) {} +bool LogDataJsonPrettyPrint(const char*, uint32_t, void (*)(const char*, uint32_t)) { return false; } +size_t strchrspn(const char *s, char c) { + const char *found = std::strchr(s, c); + return found ? size_t(found - s) : std::strlen(s); +} +#ifndef __APPLE__ +size_t strlcat(char *dst, const char *src, size_t size) { + size_t used = std::strlen(dst), add = std::strlen(src); + if (used < size) std::strncat(dst, src, size - used - 1); + return used + add; +} +#endif +''' + +TESTS = r''' +int main(int argc, char **argv) { + assert(argc == 2); + const char *mode = argv[1]; + if (!std::strcmp(mode, "berry-failure")) { + BerryLog logs; + fail_berry = true; + assert(logs.addString("button event") == nullptr); + assert(logs.isEmpty() && node == nullptr && berry_buffers == 0); + assert(format_calls == 0); + } else if (!std::strcmp(mode, "node-failure")) { + BerryLog logs; + fail_node = true; + assert(logs.addString("button event") == nullptr); + assert(logs.isEmpty() && node == nullptr && berry_buffers == 0); + assert(format_calls == 0); + } else if (!std::strcmp(mode, "berry-success")) { + BerryLog logs; + assert(logs.addString(nullptr) == nullptr && logs.isEmpty()); + auto *entry = logs.addString("event", "[", "]"); + assert(entry && !std::strcmp(entry->val().getBuffer(), "[event]")); + assert(logs.log.length() == 1 && berry_buffers == 1); + logs.reset(); + assert(logs.isEmpty() && node == nullptr && berry_buffers == 0); + entry = logs.addString("plain"); + assert(entry && !std::strcmp(entry->val().getBuffer(), "plain")); + logs.reset(); + } else { + char buffer[LOG_BUFFER_SIZE] = {}; + TasmotaGlobal.log_buffer = buffer; + AddLogData(2, "existing", " payload", " retained"); + assert(std::strstr(buffer + 2, "01:02:03.004 existing payload retained\1")); + char before[LOG_BUFFER_SIZE]; + std::memcpy(before, buffer, sizeof(buffer)); + unsigned index = TasmotaGlobal.log_buffer_pointer; + char large[1001]; + std::memset(large, 'X', sizeof(large) - 1); + large[sizeof(large) - 1] = 0; + if (!std::strcmp(mode, "log-failure")) { + fail_log = true; + AddLogData(2, large); + assert(!std::memcmp(before, buffer, sizeof(buffer))); + assert(TasmotaGlobal.log_buffer_pointer == index && log_buffers == 0); + } else if (!std::strcmp(mode, "log-success")) { + AddLogData(2, large); + assert(TasmotaGlobal.log_buffer_pointer == index + 1 && log_buffers == 0); + assert(std::strstr(buffer, "... 1000 truncated\1")); + const char *prefix = std::strchr(buffer, 'X'); + assert(prefix); + for (size_t i = 0; i < TOPSZ - 21; ++i) assert(prefix[i] == 'X'); + assert(prefix[TOPSZ - 21] == '.'); + } else { + assert(false && "unknown test mode"); + } + } + assert(node == nullptr && berry_buffers == 0 && log_buffers == 0); +} +''' + + +def read_source(path, revision=None): + if revision: + return subprocess.check_output(['git', 'show', f'{revision}:{path}'], cwd=ROOT, text=True) + return (ROOT / path).read_text() + + +def build(directory, revision=None): + berry = read_source(BERRY, revision) + berry = berry[berry.index('class Log_line {'):berry.index('class BerrySupport {')] + support = read_source(SUPPORT, revision) + support = support[support.index('void AddLogData('):support.index('\nvoid TasConsoleLDJsonPPCb(')] + # Only the oversized-log path calls malloc/free in AddLogData. + cpp = directory / 'logging.cpp' + cpp.write_text(PRELUDE + berry + '\n#define malloc log_malloc\n#define free log_free\n' + + support + '\n#undef malloc\n#undef free\n' + TESTS) + binary = directory / 'logging' + subprocess.run([os.environ.get('CXX', 'c++'), '-std=c++11', '-Wall', '-Wextra', + '-Werror', '-funsigned-char', '-fno-exceptions', '-fsanitize=address,undefined', + '-fno-omit-frame-pointer', '-I', str(ROOT / 'lib/default/TasmotaLList/src'), + str(cpp), '-o', str(binary)], check=True) + return binary + + +def run(binary, mode, expected=0): + result = subprocess.run([str(binary), mode], capture_output=True, text=True) + if result.returncode != expected: + raise AssertionError(f'{mode}: expected {expected}, got {result.returncode}\n{result.stderr}') + if expected == 86: + assert 'NULL destination passed to snprintf' in result.stderr + + +def main(): + parser = argparse.ArgumentParser(description=__doc__) + parser.add_argument('--check-baseline', metavar='GIT_REF') + args = parser.parse_args() + with tempfile.TemporaryDirectory(prefix='tasmota-log-allocation-') as temporary: + directory = Path(temporary) + if args.check_baseline: + baseline = directory / 'baseline' + baseline.mkdir() + binary = build(baseline, args.check_baseline) + for mode in ('berry-failure', 'log-failure'): + run(binary, mode, 86) + print('Baseline: both failed allocations reach a NULL snprintf destination.') + current = directory / 'current' + current.mkdir() + binary = build(current) + for mode in ('berry-failure', 'node-failure', 'berry-success', 'log-failure', 'log-success'): + run(binary, mode) + print('PASS: logging allocation failures drop safely; successful logs are preserved (5 cases, ASan/UBSan).') + + +if __name__ == '__main__': + main()