diff --git a/CMakeLists.txt b/CMakeLists.txt index b1bb8ec..de43e6f 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -39,7 +39,7 @@ set(LWIP_CONTRIB_FREERTOS_DIR "${LWIP_DIR}/contrib/ports/freertos") # link target — only the header-configured packs below do. # https://docs.cososo.co.uk/solid-syslog/getting-started/#path-a--cmake-consumer # Pinned to a commit until there is a release tag to pin to. -set(SOLIDSYSLOG_PLATFORMS "LwipRaw;Atomics" CACHE STRING "" FORCE) +set(SOLIDSYSLOG_PLATFORMS "LwipRaw;Atomics;FreeRtos" CACHE STRING "" FORCE) # Compile-time limits. Every tunable is #ifndef-guarded, so this file only needs # the ones this device wants changed. @@ -171,7 +171,7 @@ target_include_directories(baseline PRIVATE # library, or context struct sizes diverge between consumer and library. target_compile_definitions(baseline PRIVATE MBEDTLS_USER_CONFIG_FILE=${MBEDTLS_USER_CONFIG_HEADER}) -target_link_libraries(baseline PRIVATE mbedtls mbedx509 mbedcrypto SolidSyslog SolidSyslog::LwipRaw) +target_link_libraries(baseline PRIVATE mbedtls mbedx509 mbedcrypto SolidSyslog SolidSyslog::LwipRaw SolidSyslog::FreeRtos) target_link_options(baseline PRIVATE -mcpu=cortex-m3 -mthumb diff --git a/README.md b/README.md index 814acbe..4be7d09 100644 --- a/README.md +++ b/README.md @@ -10,18 +10,19 @@ 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 — Message cap +## This stage — Buffered -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. +A circular buffer in front of the sender, and a service task that drains it. `Log` now enqueues and +returns instead of sending, so the logging task is no longer held up by the network, and a mutex +makes the two sides safe on different tasks — which means logging can now happen from any task, not +just this one. -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. +Most of the cost is the ring and the service seam's stack — the send moved onto that task, so that +is where the depth moved too. -**Cost above baseline: Flash +6,032 B, RAM +1,956 B.** +**Cost above baseline: Flash +6,788 B, RAM +5,676 B.** @@ -42,6 +43,7 @@ committed as [`run-report.md`](run-report.md), and rewritten by every stage. | 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 | +| Buffered | logging that returns immediately, with the send moved off the logging task | +6,788 | +5,676 | *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 6d45b76..e2efca5 100644 --- a/app/AppConfig.h +++ b/app/AppConfig.h @@ -11,11 +11,10 @@ #define DEVICE_UART0_BASE ((uintptr_t) 0x40004000U) /* 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. */ + * it. 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 SERVICE_TASK_STACK_WORDS (configMINIMAL_STACK_SIZE * 4U) #define LOG_TASK_PRIORITY (tskIDLE_PRIORITY + 1U) #define SERVICE_TASK_PRIORITY (tskIDLE_PRIORITY + 1U) diff --git a/app/main.c b/app/main.c index 25fa459..e42240a 100644 --- a/app/main.c +++ b/app/main.c @@ -66,10 +66,11 @@ static void HarnessTask(void* parameters) bool logIdle = LogTask_WaitIdle(2000U); bool serviceIdle = ServiceTask_WaitIdle(2000U); - /* Emitted before the figures are taken: the record goes out inline on the - * log task's stack, so its stack figure only means anything afterwards. */ + /* Log enqueues and returns; the service task sends it, so give that a moment + * before the figures are taken. What arrived is the collector's word. */ bool logged = LogTask_EmitOnce(5000U); (void) printf("[device] first record logged: %s\n", logged ? "yes" : "FAILED"); + vTaskDelay(pdMS_TO_TICKS(500U)); (void) Measure_Report(); diff --git a/app/syslog/Syslog.c b/app/syslog/Syslog.c index 36b431d..9753b82 100644 --- a/app/syslog/Syslog.c +++ b/app/syslog/Syslog.c @@ -1,24 +1,25 @@ /* See Syslog.h. * - * The smallest wiring that delivers: a UDP sender over lwIP, with a passthrough - * buffer in front of it. Passthrough means Log sends inline on the calling task - * — no queue, no background drain, nothing to service. + * A UDP sender over lwIP behind a circular buffer: Log enqueues and returns, and + * the service task drains and sends. The mutex is what makes those two sides + * safe on different tasks. * * Unlike a header field, an SD PARAM has no NILVALUE: an unset one is omitted * entirely rather than written as "-". */ #include "Syslog.h" +#include "SolidSyslogCircularBuffer.h" #include "SolidSyslogConfig.h" #include "SolidSyslogEndpoint.h" #include "SolidSyslogEndpointHost.h" +#include "SolidSyslogFreeRtosMutex.h" #include "SolidSyslogLwipRawAddress.h" #include "SolidSyslogLwipRawDatagram.h" #include "SolidSyslogLwipRawMarshal.h" #include "SolidSyslogLwipRawResolver.h" #include "SolidSyslogMetaSd.h" #include "SolidSyslogNullStore.h" -#include "SolidSyslogPassthroughBuffer.h" #include "SolidSyslogStdAtomicCounter.h" #include "SolidSyslogUdpSender.h" #include "SyslogFields.h" @@ -35,7 +36,12 @@ #define SYSLOG_COLLECTOR_HOST "10.0.2.2" #define SYSLOG_COLLECTOR_PORT ((uint16_t) 5514U) +/* Depth enough to absorb a burst while the sender is busy, without sizing for a + * backlog the store is there to hold. */ +#define SYSLOG_BUFFER_RECORDS 8U + static struct SolidSyslog* s_logger = NULL; +static uint8_t s_ring[SOLIDSYSLOG_CIRCULAR_BUFFER_RING_BYTES(SYSLOG_BUFFER_RECORDS)]; /* The logger reads these on every record, so they outlive Syslog_Start. */ static struct SolidSyslogStructuredData* s_sd[1]; @@ -84,7 +90,7 @@ void Syslog_Start(void) s_sd[0] = SolidSyslogMetaSd_Create(&metaConfig); struct SolidSyslogConfig config = { - .Buffer = SolidSyslogPassthroughBuffer_Create(sender), + .Buffer = SolidSyslogCircularBuffer_Create(SolidSyslogFreeRtosMutex_Create(), s_ring, sizeof(s_ring)), .Sender = sender, /* No store-and-forward here. The Null object rather than NULL is how * that is said out loud — NULL is reported as a fault. */ diff --git a/app/tasks/LogTask.h b/app/tasks/LogTask.h index a822609..5816f50 100644 --- a/app/tasks/LogTask.h +++ b/app/tasks/LogTask.h @@ -12,9 +12,9 @@ extern "C" { #endif - /* The log source seam: the one place this device logs from. Its stack figure - * only means anything if logging happens here and not on the harness that - * asks for it. */ + /* The log source seam. With a buffer in front of the sender any task could + * call Log for the same cost; this stays one task so the stack figure has a + * single owner. */ bool LogTask_Create(void); TaskHandle_t LogTask_Handle(void); diff --git a/app/tasks/ServiceTask.c b/app/tasks/ServiceTask.c index 6cbbb80..735ae05 100644 --- a/app/tasks/ServiceTask.c +++ b/app/tasks/ServiceTask.c @@ -3,9 +3,14 @@ #include "ServiceTask.h" #include "AppConfig.h" +#include "Syslog.h" + +#include "SolidSyslog.h" #include "semphr.h" +#define SERVICE_POLL_MS 20U + static TaskHandle_t s_handle = NULL; static StaticTask_t s_taskBuffer; static StackType_t s_stack[SERVICE_TASK_STACK_WORDS]; @@ -20,7 +25,11 @@ static void ServiceTask_Entry(void* parameters) for (;;) { - vTaskDelay(portMAX_DELAY); + /* Service returns a status, which a device wanting more sophisticated + * scheduling can drive from. A loop with a delay is the simplest model + * that works. */ + (void) SolidSyslog_Service(Syslog_Handle()); + vTaskDelay(pdMS_TO_TICKS(SERVICE_POLL_MS)); } } diff --git a/measurements/buffered.csv b/measurements/buffered.csv new file mode 100644 index 0000000..6165130 --- /dev/null +++ b/measurements/buffered.csv @@ -0,0 +1,13 @@ +# buffered 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,356608 +flash_data,488 +static_bss,116380 +heap_used,4440 +mbedtls_peak,21316 +mbedtls_free,11452 +lwip_mem_free,7576 +lwip_pbufs_free,13 +stack_log,568 +stack_service,780 +stack_harness,2848 diff --git a/measurements/stages.tsv b/measurements/stages.tsv index 16bdb0f..34c934c 100644 --- a/measurements/stages.tsv +++ b/measurements/stages.tsv @@ -17,3 +17,4 @@ 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 +buffered Buffered logging that returns immediately, with the send moved off the logging task diff --git a/run-report.md b/run-report.md index 90ef4fb..9ba08ba 100644 --- a/run-report.md +++ b/run-report.md @@ -1,4 +1,4 @@ -# solid-syslog-example — run (message-cap) +# solid-syslog-example — run (buffered) ## Device (self-measured) @@ -10,16 +10,16 @@ [device] first record logged: yes [report] --- SolidSyslog cost above baseline (simulated existing application) --- [report] key,current,baseline,used_above_baseline -[report] flash_text,355868,349992,5876 -[report] flash_data,472,316,156 -[report] static_bss,112676,110876,1800 +[report] flash_text,356608,349992,6616 +[report] flash_data,488,316,172 +[report] static_bss,116380,110876,5504 [report] heap_used,4440,4440,0 -[report] mbedtls_peak,21288,21332,-44 -[report] mbedtls_free,11480,11436,44 +[report] mbedtls_peak,21200,21332,-132 +[report] mbedtls_free,11568,11436,132 [report] lwip_mem_free,7576,7576,0 [report] lwip_pbufs_free,13,14,-1 -[report] stack_log,800,120,680 -[report] stack_service,52,52,0 +[report] stack_log,568,120,448 +[report] stack_service,780,52,728 [report] stack_harness,2848,2840,8 [report] --- end --- [device] ready @@ -29,7 +29,7 @@ ```text text data bss dec hex filename - 355860 480 112676 469016 72818 /w/build/baseline-cross/baseline.elf + 356600 496 116380 473476 73984 /w/build/baseline-cross/baseline.elf ``` ## Listeners (proved before the device ran) @@ -47,23 +47,23 @@ ## Collector (syslog-ng) received ```text -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 +wire <134>1 2026-07-29T07:17:47.410000Z 10.0.2.15 solid-syslog-example - BOOT [meta sequenceId="1"] device started +parsed PRIORITY=134 TIMESTAMP=2026-07-29T07:17:47+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/message-cap.csv) +## Self-check (vs measurements/buffered.csv) ```text - OK flash_text: 355868 (expected 355868, Δ0) - OK flash_data: 472 (expected 472, Δ0) - OK static_bss: 112676 (expected 112676, Δ0) + OK flash_text: 356608 (expected 356608, Δ0) + OK flash_data: 488 (expected 488, Δ0) + OK static_bss: 116380 (expected 116380, Δ0) OK heap_used: 4440 (expected 4440, Δ0) - OK mbedtls_peak: 21288 (expected 21228, Δ60) - OK mbedtls_free: 11480 (expected 11540, Δ60) + OK mbedtls_peak: 21200 (expected 21316, Δ116) + OK mbedtls_free: 11568 (expected 11452, Δ116) OK lwip_mem_free: 7576 (expected 7576, Δ0) OK lwip_pbufs_free: 13 (expected 13, Δ0) - OK stack_log: 800 (expected 800, Δ0) - OK stack_service: 52 (expected 52, Δ0) + OK stack_log: 568 (expected 568, Δ0) + OK stack_service: 780 (expected 780, Δ0) OK stack_harness: 2848 (expected 2848, Δ0) ```