From b63fd2129d8eca22872c45a5cc1a6393ddeed4a0 Mon Sep 17 00:00:00 2001 From: David Cozens Date: Tue, 28 Jul 2026 23:33:58 +0100 Subject: [PATCH] feat: size the message cap to this device's records MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit SOLIDSYSLOG_MAX_MESSAGE_SIZE drops from the library's default of 2048 to 256. RFC 5424 section 6.1 says a receiver should accept 2048; over UDP, RFC 5426 section 3.2 guarantees only 480. This device's records are far shorter than either, so 256 stays well inside every guarantee and anything longer is truncated rather than dropped. Flash +6,032 B (unchanged) RAM +1,956 B (+1,520) Log stack +680 B (+664) The cost is all RAM, and not where it looks. Setting the cap made the log task overflow its stack outright: [device] FATAL: stack overflow in task log The record is built on the stack of whichever task calls Log, and the log seam was still at the FreeRTOS minimum it inherited from the baseline. Measured at 800 bytes used, so the seam grows to 2 KiB by the same two-fold rule everything else here uses. That is 1,536 bytes of stack allocation against a net rise of 1,520: the smaller cap and address pool give 16 back. Worth knowing, and not yet explained: the previous stage formatted and sent the same record on the same 512-byte stack and reported 136 bytes used, with no overflow and the record arriving intact. Introducing the tunables file is what moved the formatter onto the caller's stack. The failure was loud rather than silent — configCHECK_FOR_STACK_OVERFLOW is 2, with a hook — which is the only reason this is a paragraph and not a corruption bug. Co-Authored-By: Claude Opus 5 (1M context) --- CMakeLists.txt | 4 ++++ README.md | 13 ++++++++----- app/AppConfig.h | 9 +++++---- app/config/solid_syslog_tunables.h | 18 ++++++++++++++++++ measurements/message-cap.csv | 13 +++++++++++++ measurements/stages.tsv | 1 + run-report.md | 26 +++++++++++++------------- 7 files changed, 62 insertions(+), 22 deletions(-) create mode 100644 app/config/solid_syslog_tunables.h create mode 100644 measurements/message-cap.csv diff --git a/CMakeLists.txt b/CMakeLists.txt index 97065b6..b1bb8ec 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -41,6 +41,10 @@ set(LWIP_CONTRIB_FREERTOS_DIR "${LWIP_DIR}/contrib/ports/freertos") # Pinned to a commit until there is a release tag to pin to. set(SOLIDSYSLOG_PLATFORMS "LwipRaw;Atomics" CACHE STRING "" FORCE) +# Compile-time limits. Every tunable is #ifndef-guarded, so this file only needs +# the ones this device wants changed. +set(SOLIDSYSLOG_USER_TUNABLES_FILE "${APP_DIR}/config/solid_syslog_tunables.h") + include(FetchContent) FetchContent_Declare(SolidSyslog GIT_REPOSITORY https://github.com/cososo-ltd/solid-syslog.git diff --git a/README.md b/README.md index b3e5059..814acbe 100644 --- a/README.md +++ b/README.md @@ -10,16 +10,18 @@ It builds on a baseline that simulates the sort of device you might be adding th measures itself: see [docs/baseline.md](docs/baseline.md) for what the baseline is, how the figures are made, and how to run it. -## This stage — Sequence numbers +## This stage — Message cap -Every record carries `[meta sequenceId="N"]`. The counter increments once per record *formatted*, -not per record delivered, so a record that never arrives leaves a gap rather than no trace at all. +The longest record this device will emit is capped at 256 bytes, down from the library's default of +2048. Anything longer is truncated rather than dropped, and 256 sits well inside what RFC 5426 +guarantees a UDP receiver will accept. -That earns its place from the next stage on, where a full buffer can start dropping records. +The cost is not in flash — it is RAM, because the record is built on the stack of whichever task +logs, and that seam had been sitting at the FreeRTOS minimum. -**Cost above baseline: Flash +6,032 B, RAM +436 B.** +**Cost above baseline: Flash +6,032 B, RAM +1,956 B.** @@ -39,6 +41,7 @@ committed as [`run-report.md`](run-report.md), and rewritten by every stage. | First record | a valid RFC 5424 record on the wire, over UDP | +4,716 | +372 | | Header fields | a timestamped record naming the device, instead of nil values | +5,100 | +372 | | Sequence numbers | every record numbered, so a gap in the sequence is visible | +6,032 | +436 | +| Message cap | a bounded record size, so a long message truncates instead of being dropped | +6,032 | +1,956 | *Deltas are bytes above the baseline, which is itself Flash 350,308 B, RAM 111,192 B.* diff --git a/app/AppConfig.h b/app/AppConfig.h index aa43269..6d45b76 100644 --- a/app/AppConfig.h +++ b/app/AppConfig.h @@ -10,10 +10,11 @@ /* CMSDK UART0 on the mps2-an385, surfaced by QEMU over -serial stdio. */ #define DEVICE_UART0_BASE ((uintptr_t) 0x40004000U) -/* Both seams are idle, so both get the FreeRTOS floor — twice what an idle seam - * measures is well below it. Whatever deepens one grows it there. The reported - * figure is high-water usage, which does not depend on the allocation. */ -#define LOG_TASK_STACK_WORDS (configMINIMAL_STACK_SIZE) +/* Twice the measured high-water mark, or the FreeRTOS floor where that is below + * it — as the service seam still is, being idle. Whatever deepens a seam grows + * it here and is charged for it. The reported figure is high-water usage, which + * does not depend on the allocation. */ +#define LOG_TASK_STACK_WORDS (configMINIMAL_STACK_SIZE * 4U) #define SERVICE_TASK_STACK_WORDS (configMINIMAL_STACK_SIZE) #define LOG_TASK_PRIORITY (tskIDLE_PRIORITY + 1U) #define SERVICE_TASK_PRIORITY (tskIDLE_PRIORITY + 1U) diff --git a/app/config/solid_syslog_tunables.h b/app/config/solid_syslog_tunables.h new file mode 100644 index 0000000..fc5ca6f --- /dev/null +++ b/app/config/solid_syslog_tunables.h @@ -0,0 +1,18 @@ +/* SolidSyslog compile-time overrides for this device. Reached via + * SOLIDSYSLOG_USER_TUNABLES_FILE; anything not set here keeps the library + * default from SolidSyslogTunablesDefaults.h. */ +#ifndef SOLID_SYSLOG_TUNABLES_H +#define SOLID_SYSLOG_TUNABLES_H + +/* The longest record this device will emit. The library defaults to 2048, the + * size RFC 5424 section 6.1 says a receiver should accept; over UDP, RFC 5426 + * section 3.2 guarantees only that 480 will be accepted. This device's records are + * far shorter, so 256 stays well inside every guarantee and anything longer is + * truncated rather than dropped. */ +#define SOLIDSYSLOG_MAX_MESSAGE_SIZE 256U + +/* One sender, so one destination address. The default of 3 suits a device + * running UDP, plain TCP and TLS at once. */ +#define SOLIDSYSLOG_ADDRESS_POOL_SIZE 1U + +#endif /* SOLID_SYSLOG_TUNABLES_H */ diff --git a/measurements/message-cap.csv b/measurements/message-cap.csv new file mode 100644 index 0000000..40ddd4c --- /dev/null +++ b/measurements/message-cap.csv @@ -0,0 +1,13 @@ +# message-cap figures (bytes) — captured by scripts/run.sh (CAPTURE=1). +# The device reads measurements/Baseline.csv as its frozen baseline and reports current-minus-Baseline. +flash_text,355868 +flash_data,472 +static_bss,112676 +heap_used,4440 +mbedtls_peak,21228 +mbedtls_free,11540 +lwip_mem_free,7576 +lwip_pbufs_free,13 +stack_log,800 +stack_service,52 +stack_harness,2848 diff --git a/measurements/stages.tsv b/measurements/stages.tsv index bdbabac..16bdb0f 100644 --- a/measurements/stages.tsv +++ b/measurements/stages.tsv @@ -16,3 +16,4 @@ logger Logger created the logger object, reporting exactly what is still missing udp First record a valid RFC 5424 record on the wire, over UDP header-fields Header fields a timestamped record naming the device, instead of nil values sequence-id Sequence numbers every record numbered, so a gap in the sequence is visible +message-cap Message cap a bounded record size, so a long message truncates instead of being dropped diff --git a/run-report.md b/run-report.md index 37d31f1..90ef4fb 100644 --- a/run-report.md +++ b/run-report.md @@ -1,4 +1,4 @@ -# solid-syslog-example — run (sequence-id) +# solid-syslog-example — run (message-cap) ## Device (self-measured) @@ -12,13 +12,13 @@ [report] key,current,baseline,used_above_baseline [report] flash_text,355868,349992,5876 [report] flash_data,472,316,156 -[report] static_bss,111156,110876,280 +[report] static_bss,112676,110876,1800 [report] heap_used,4440,4440,0 -[report] mbedtls_peak,21332,21332,0 -[report] mbedtls_free,11436,11436,0 +[report] mbedtls_peak,21288,21332,-44 +[report] mbedtls_free,11480,11436,44 [report] lwip_mem_free,7576,7576,0 [report] lwip_pbufs_free,13,14,-1 -[report] stack_log,136,120,16 +[report] stack_log,800,120,680 [report] stack_service,52,52,0 [report] stack_harness,2848,2840,8 [report] --- end --- @@ -29,7 +29,7 @@ ```text text data bss dec hex filename - 355860 480 111156 467496 72228 /w/build/baseline-cross/baseline.elf + 355860 480 112676 469016 72818 /w/build/baseline-cross/baseline.elf ``` ## Listeners (proved before the device ran) @@ -47,22 +47,22 @@ ## Collector (syslog-ng) received ```text -wire <134>1 2026-07-29T07:15:27.620000Z 10.0.2.15 solid-syslog-example - BOOT [meta sequenceId="1"] device started -parsed PRIORITY=134 TIMESTAMP=2026-07-29T07:15:27+00:00 HOSTNAME=10.0.2.15 APP_NAME=solid-syslog-example PROCID= MSGID=BOOT STRUCTURED_DATA=[meta sequenceId="1"] MSG=device started +wire <134>1 2026-07-29T07:16:37.410000Z 10.0.2.15 solid-syslog-example - BOOT [meta sequenceId="1"] device started +parsed PRIORITY=134 TIMESTAMP=2026-07-29T07:16:37+00:00 HOSTNAME=10.0.2.15 APP_NAME=solid-syslog-example PROCID= MSGID=BOOT STRUCTURED_DATA=[meta sequenceId="1"] MSG=device started ``` -## Self-check (vs measurements/sequence-id.csv) +## Self-check (vs measurements/message-cap.csv) ```text OK flash_text: 355868 (expected 355868, Δ0) OK flash_data: 472 (expected 472, Δ0) - OK static_bss: 111156 (expected 111156, Δ0) + OK static_bss: 112676 (expected 112676, Δ0) OK heap_used: 4440 (expected 4440, Δ0) - OK mbedtls_peak: 21332 (expected 21344, Δ12) - OK mbedtls_free: 11436 (expected 11424, Δ12) + OK mbedtls_peak: 21288 (expected 21228, Δ60) + OK mbedtls_free: 11480 (expected 11540, Δ60) OK lwip_mem_free: 7576 (expected 7576, Δ0) OK lwip_pbufs_free: 13 (expected 13, Δ0) - OK stack_log: 136 (expected 136, Δ0) + OK stack_log: 800 (expected 800, Δ0) OK stack_service: 52 (expected 52, Δ0) OK stack_harness: 2848 (expected 2848, Δ0) ```