diff --git a/README.md b/README.md index 6107596..95c1355 100644 --- a/README.md +++ b/README.md @@ -10,41 +10,49 @@ 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 — Buffered +## This stage — TCP -A `SolidSyslogCircularBuffer` between `SolidSyslog_Log` and the sender, drained by a service task -calling `SolidSyslog_Service`. `SolidSyslog_Log` formats, enqueues and returns; the service task -does the I/O. +UDP to TCP, by putting a `SolidSyslogStreamSender` over an lwIP TCP stream. The network +retransmits rather than dropping, and a send fails when the collector is gone instead of succeeding +into a void. Records are framed by octet count per RFC 6587, which is what a receiver expects on a +stream transport. ```c -static uint8_t s_ring[SOLIDSYSLOG_CIRCULAR_BUFFER_RING_BYTES(SYSLOG_BUFFER_RECORDS)]; - -.Buffer = SolidSyslogCircularBuffer_Create(SolidSyslogFreeRtosMutex_Create(), s_ring, sizeof(s_ring)), +struct SolidSyslogLwipRawTcpStreamConfig tcpConfig = {.Sleep = SyslogSleep}; + +struct SolidSyslogStreamSenderConfig senderConfig = { + .Resolver = SolidSyslogLwipRawResolver_Create(), + .Stream = SolidSyslogLwipRawTcpStream_Create(&tcpConfig), + .Address = SolidSyslogLwipRawAddress_Create(), + .Endpoint = CollectorEndpoint, +}; +struct SolidSyslogSender* sender = SolidSyslogStreamSender_Create(&senderConfig); ``` -This separates logging an event from sending it. `SolidSyslog_Log` becomes safe to call from any -number of tasks, and cheap enough to call from the place the event actually happens rather than -from somewhere convenient later. Nothing that logs waits on the network. +Taken with the sequence number, this completes the loss story: the transport detects loss where it +happens, and the sequence reveals afterwards anything the transport could not. It is also what +makes the delivery-failed and delivery-restored events from the error-handler stage meaningful. + +The store is still the Null object, so a record whose send fails is reported but not kept. The +device learns that delivery is failing without yet being able to do anything about it; retaining +the record is the store stage's job. -**A whole record now passes through both seams,** and the depth follows it. The log task formats -one; the service task drains one and sends it. Sized at the RTOS floor, the service task did not -merely trip its overflow hook — it locked the CPU up, because a frame that large clears the guard -band entirely rather than growing into it. Both seams now hold a record and their onward call, and -both are tightened against measured high-water marks at the end. +TCP before TLS is deliberate. It is the smaller step — a stream, a connect and a framing rule, with +no certificates in the picture — and it is what a later store-and-forward stage will spool onto. -The mutex is what makes the enqueue and drain sides safe on different tasks, and it comes from the -RTOS — which is what brings the `FreeRtos` platform into the build. A single-task device injects -`SolidSyslogNullMutex_Get()` instead and pays nothing. +The stream takes a `Sleep` callback because a connect is not instantaneous and the library will not +pick a blocking primitive on your behalf; one `vTaskDelay` is the whole of it. -`SolidSyslog_Service` returns a status a device wanting more sophisticated scheduling can drive -from. A loop with a delay is the simplest model that works. +**When you need it.** If the device must know that delivery is failing — to raise an alarm, to fall +back, to start storing. Over UDP it never finds out. -**When you need it.** Once logging and sending are decoupled, the buffer has to absorb however many -events can be logged before it is next serviced. It also makes logging from multiple tasks safe. +> RFC 6587 is Historic, and the IESG recommends TLS over plain TCP for new deployments. Plain TCP +> is here for collectors you do not control, and as the step a later storage stage will spool onto, +> before cryptography arrives. -**Cost above baseline: Flash +6,804 B, RAM +7,484 B.** +**Cost above baseline: Flash +7,348 B, RAM +7,664 B.** @@ -65,6 +73,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,108 | +1,908 | | Sequence numbers | every record numbered, so a gap in the sequence is visible | +6,052 | +1,972 | | Buffered | logging that returns immediately, with the send moved off the logging task | +6,804 | +7,484 | +| TCP | records the network retransmits instead of dropping, and a send that fails when the collector is gone | +7,348 | +7,664 | *Deltas are bytes above the baseline, which is itself Flash 350,124 B, RAM 111,192 B.* diff --git a/app/syslog/Syslog.c b/app/syslog/Syslog.c index 9753b82..c571c98 100644 --- a/app/syslog/Syslog.c +++ b/app/syslog/Syslog.c @@ -1,6 +1,6 @@ /* See Syslog.h. * - * A UDP sender over lwIP behind a circular buffer: Log enqueues and returns, and + * A TCP stream 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. * @@ -15,17 +15,20 @@ #include "SolidSyslogEndpointHost.h" #include "SolidSyslogFreeRtosMutex.h" #include "SolidSyslogLwipRawAddress.h" -#include "SolidSyslogLwipRawDatagram.h" #include "SolidSyslogLwipRawMarshal.h" #include "SolidSyslogLwipRawResolver.h" +#include "SolidSyslogLwipRawTcpStream.h" #include "SolidSyslogMetaSd.h" #include "SolidSyslogNullStore.h" #include "SolidSyslogStdAtomicCounter.h" -#include "SolidSyslogUdpSender.h" +#include "SolidSyslogStreamSender.h" #include "SyslogFields.h" #include "lwip/tcpip.h" +#include "FreeRTOS.h" +#include "task.h" + #include #include #include @@ -34,7 +37,7 @@ * the resolver numeric-only — no DNS, so no LWIP_DNS and no DNS resolver * component to compile. */ #define SYSLOG_COLLECTOR_HOST "10.0.2.2" -#define SYSLOG_COLLECTOR_PORT ((uint16_t) 5514U) +#define SYSLOG_COLLECTOR_PORT ((uint16_t) 5601U) /* Depth enough to absorb a burst while the sender is busy, without sizing for a * backlog the store is there to hold. */ @@ -46,7 +49,13 @@ static uint8_t s_ring[SOLIDSYSLOG_CIRCULAR_BUFFER_RING_BYTES(SYSLOG_BUFFER_RECOR /* The logger reads these on every record, so they outlive Syslog_Start. */ static struct SolidSyslogStructuredData* s_sd[1]; -/* Every lwIP Raw call the datagram makes has to happen on the thread that owns +/* Bounds the connect spin so it yields instead of busy-waiting. */ +static void SyslogSleep(int milliseconds) +{ + vTaskDelay(pdMS_TO_TICKS(milliseconds)); +} + +/* Every lwIP Raw call the stream makes has to happen on the thread that owns * the lwIP core. lwipopts.h sets LWIP_TCPIP_CORE_LOCKING, so taking the core * lock in the caller's own task is simpler and cheaper than posting to the tcpip * mailbox — and unconditionally synchronous, which the marshal contract @@ -73,16 +82,17 @@ void Syslog_Start(void) { SolidSyslogLwipRaw_SetMarshal(LwipCoreLockMarshal); - /* A numeric resolver to parse the literal, a datagram for the socket, and an - * address slot for the resolver to write into. No EndpointVersion — this - * collector never moves, so the sender resolves once and pins it. */ - struct SolidSyslogUdpSenderConfig senderConfig = { + struct SolidSyslogLwipRawTcpStreamConfig tcpConfig = {.Sleep = SyslogSleep}; + + /* No EndpointVersion — this collector never moves, so the sender resolves + * once and pins it. */ + struct SolidSyslogStreamSenderConfig senderConfig = { .Resolver = SolidSyslogLwipRawResolver_Create(), - .Datagram = SolidSyslogLwipRawDatagram_Create(), + .Stream = SolidSyslogLwipRawTcpStream_Create(&tcpConfig), .Address = SolidSyslogLwipRawAddress_Create(), .Endpoint = CollectorEndpoint, }; - struct SolidSyslogSender* sender = SolidSyslogUdpSender_Create(&senderConfig); + struct SolidSyslogSender* sender = SolidSyslogStreamSender_Create(&senderConfig); /* One counter Increment per record formatted, so a record that never reaches * the collector leaves a gap in the sequence rather than no trace at all. */ diff --git a/measurements/stages.tsv b/measurements/stages.tsv index 8639976..b3b7d3c 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 buffered Buffered logging that returns immediately, with the send moved off the logging task +tcp TCP records the network retransmits instead of dropping, and a send that fails when the collector is gone diff --git a/measurements/tcp.csv b/measurements/tcp.csv new file mode 100644 index 0000000..f85484c --- /dev/null +++ b/measurements/tcp.csv @@ -0,0 +1,13 @@ +# tcp 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,356984 +flash_data,488 +static_bss,118368 +heap_used,4440 +mbedtls_peak,21288 +mbedtls_free,11480 +lwip_mem_free,7576 +lwip_pbufs_free,13 +stack_log,792 +stack_service,948 +stack_harness,2848 diff --git a/run-report.md b/run-report.md index b8b2108..a2ca7b5 100644 --- a/run-report.md +++ b/run-report.md @@ -1,4 +1,4 @@ -# solid-syslog-example — run (buffered) +# solid-syslog-example — run (tcp) ## 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,356440,349808,6632 +[report] flash_text,356984,349808,7176 [report] flash_data,488,316,172 -[report] static_bss,118188,110876,7312 +[report] static_bss,118368,110876,7492 [report] heap_used,4440,4440,0 -[report] mbedtls_peak,21236,21328,-92 -[report] mbedtls_free,11532,11440,92 +[report] mbedtls_peak,21328,21328,0 +[report] mbedtls_free,11440,11440,0 [report] lwip_mem_free,7576,7576,0 -[report] lwip_pbufs_free,13,13,0 +[report] lwip_pbufs_free,14,13,1 [report] stack_log,792,120,672 -[report] stack_service,1004,52,952 +[report] stack_service,948,52,896 [report] stack_harness,2848,2840,8 [report] --- end --- [device] ready @@ -29,7 +29,7 @@ ```text text data bss dec hex filename - 356432 496 118188 475116 73fec /w/build/baseline.elf + 356976 496 118368 475840 742c0 /w/build/baseline.elf ``` ## Listeners (proved before the device ran) @@ -47,23 +47,23 @@ ## Collector (syslog-ng) received ```text -wire <134>1 2026-08-16T19:29:06.310000Z 10.0.2.15 solid-syslog-example - BOOT [meta sequenceId="1"] device started -parsed PRIORITY=134 TIMESTAMP=2026-08-16T19:29:06+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-08-16T19:31:24.850000Z 10.0.2.15 solid-syslog-example - BOOT [meta sequenceId="1"] device started +parsed PRIORITY=134 TIMESTAMP=2026-08-16T19:31:24+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/buffered.csv) +## Self-check (vs measurements/tcp.csv) ```text - OK flash_text: 356440 (expected 356440, Δ0) + OK flash_text: 356984 (expected 356984, Δ0) OK flash_data: 488 (expected 488, Δ0) - OK static_bss: 118188 (expected 118188, Δ0) + OK static_bss: 118368 (expected 118368, Δ0) OK heap_used: 4440 (expected 4440, Δ0) - OK mbedtls_peak: 21236 (expected 21332, Δ96) - OK mbedtls_free: 11532 (expected 11436, Δ96) + OK mbedtls_peak: 21328 (expected 21288, Δ40) + OK mbedtls_free: 11440 (expected 11480, Δ40) OK lwip_mem_free: 7576 (expected 7576, Δ0) - OK lwip_pbufs_free: 13 (expected 13, Δ0) + OK lwip_pbufs_free: 14 (expected 13, Δ1) OK stack_log: 792 (expected 792, Δ0) - OK stack_service: 1004 (expected 1004, Δ0) + OK stack_service: 948 (expected 948, Δ0) OK stack_harness: 2848 (expected 2848, Δ0) ```