diff --git a/README.md b/README.md index 0ff8562..834b954 100644 --- a/README.md +++ b/README.md @@ -10,15 +10,15 @@ 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 — TCP +## This stage — Time quality -The sender is a TCP stream to the collector on 5601 instead of a UDP datagram, with records framed -by octet count as a receiver on a stream expects. A record the network drops is retransmitted -rather than lost, and a send to a collector that is not there fails instead of quietly succeeding. +The record gains a `timeQuality` SD-ELEMENT and a `sysUpTime` PARAM on `meta`. This device's clock +free-runs on the tick after one reading at boot, so it reports `isSynced="0"` and the collector +knows how far to trust the timestamp. -**Cost above baseline: Flash +7,320 B, RAM +5,856 B.** +**Cost above baseline: Flash +7,612 B, RAM +5,880 B.** @@ -41,6 +41,7 @@ committed as [`run-report.md`](run-report.md), and rewritten by every stage. | 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 | | TCP | records the network retransmits instead of dropping, and a send that fails when the collector is gone | +7,320 | +5,856 | +| Time quality | a timestamp the collector knows how far to trust, and an uptime that tells a reboot from a counter wrap | +7,612 | +5,880 | *Deltas are bytes above the baseline, which is itself Flash 350,308 B, RAM 111,192 B.* diff --git a/app/syslog/Syslog.c b/app/syslog/Syslog.c index c571c98..3b7043f 100644 --- a/app/syslog/Syslog.c +++ b/app/syslog/Syslog.c @@ -14,6 +14,7 @@ #include "SolidSyslogEndpoint.h" #include "SolidSyslogEndpointHost.h" #include "SolidSyslogFreeRtosMutex.h" +#include "SolidSyslogFreeRtosSysUpTime.h" #include "SolidSyslogLwipRawAddress.h" #include "SolidSyslogLwipRawMarshal.h" #include "SolidSyslogLwipRawResolver.h" @@ -22,6 +23,8 @@ #include "SolidSyslogNullStore.h" #include "SolidSyslogStdAtomicCounter.h" #include "SolidSyslogStreamSender.h" +#include "SolidSyslogTimeQuality.h" +#include "SolidSyslogTimeQualitySd.h" #include "SyslogFields.h" #include "lwip/tcpip.h" @@ -47,7 +50,16 @@ 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]; +static struct SolidSyslogStructuredData* s_sd[2]; + +/* One reading at boot, then free-running on the tick — enough to stamp a record, + * not synchronisation. */ +static void SyslogTimeQuality(struct SolidSyslogTimeQuality* timeQuality) +{ + timeQuality->TzKnown = true; + timeQuality->IsSynced = false; + timeQuality->SyncAccuracyMicroseconds = SOLIDSYSLOG_SYNC_ACCURACY_OMIT; +} /* Bounds the connect spin so it yields instead of busy-waiting. */ static void SyslogSleep(int milliseconds) @@ -96,8 +108,12 @@ void Syslog_Start(void) /* 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. */ - struct SolidSyslogMetaSdConfig metaConfig = {.Counter = SolidSyslogStdAtomicCounter_Create()}; + struct SolidSyslogMetaSdConfig metaConfig = { + .Counter = SolidSyslogStdAtomicCounter_Create(), + .GetSysUpTime = SolidSyslogFreeRtosSysUpTime_Get, + }; s_sd[0] = SolidSyslogMetaSd_Create(&metaConfig); + s_sd[1] = SolidSyslogTimeQualitySd_Create(SyslogTimeQuality); struct SolidSyslogConfig config = { .Buffer = SolidSyslogCircularBuffer_Create(SolidSyslogFreeRtosMutex_Create(), s_ring, sizeof(s_ring)), diff --git a/measurements/stages.tsv b/measurements/stages.tsv index 3e57072..e2dc788 100644 --- a/measurements/stages.tsv +++ b/measurements/stages.tsv @@ -19,3 +19,4 @@ sequence-id Sequence numbers every record numbered, so a gap in the sequence is 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 tcp TCP records the network retransmits instead of dropping, and a send that fails when the collector is gone +time-quality Time quality a timestamp the collector knows how far to trust, and an uptime that tells a reboot from a counter wrap diff --git a/measurements/time-quality.csv b/measurements/time-quality.csv new file mode 100644 index 0000000..d1b6d46 --- /dev/null +++ b/measurements/time-quality.csv @@ -0,0 +1,13 @@ +# time-quality 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,357424 +flash_data,496 +static_bss,116576 +heap_used,4440 +mbedtls_peak,21352 +mbedtls_free,11416 +lwip_mem_free,7576 +lwip_pbufs_free,13 +stack_log,568 +stack_service,724 +stack_harness,2848 diff --git a/run-report.md b/run-report.md index d9c97ab..5156d1c 100644 --- a/run-report.md +++ b/run-report.md @@ -1,4 +1,4 @@ -# solid-syslog-example — run (tcp) +# solid-syslog-example — run (time-quality) ## Device (self-measured) @@ -10,12 +10,12 @@ [device] first record logged: yes [report] --- SolidSyslog cost above baseline (simulated existing application) --- [report] key,current,baseline,used_above_baseline -[report] flash_text,357140,349992,7148 -[report] flash_data,488,316,172 -[report] static_bss,116560,110876,5684 +[report] flash_text,357424,349992,7432 +[report] flash_data,496,316,180 +[report] static_bss,116576,110876,5700 [report] heap_used,4440,4440,0 -[report] mbedtls_peak,21328,21332,-4 -[report] mbedtls_free,11440,11436,4 +[report] mbedtls_peak,21352,21332,20 +[report] mbedtls_free,11416,11436,-20 [report] lwip_mem_free,7576,7576,0 [report] lwip_pbufs_free,13,14,-1 [report] stack_log,568,120,448 @@ -29,7 +29,7 @@ ```text text data bss dec hex filename - 357132 496 116560 474188 73c4c /w/build/baseline-cross/baseline.elf + 357416 504 116576 474496 73d80 /w/build/baseline-cross/baseline.elf ``` ## Listeners (proved before the device ran) @@ -47,19 +47,19 @@ ## Collector (syslog-ng) received ```text -wire <134>1 2026-07-29T07:30:26.440000Z 10.0.2.15 solid-syslog-example - BOOT [meta sequenceId="1"] device started -parsed PRIORITY=134 TIMESTAMP=2026-07-29T07:30:26+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:42:02.620000Z 10.0.2.15 solid-syslog-example - BOOT [meta sequenceId="1" sysUpTime="362"][timeQuality tzKnown="1" isSynced="0"] device started +parsed PRIORITY=134 TIMESTAMP=2026-07-29T07:42:02+00:00 HOSTNAME=10.0.2.15 APP_NAME=solid-syslog-example PROCID= MSGID=BOOT STRUCTURED_DATA=[meta sequenceId="1" sysUpTime="362"][timeQuality tzKnown="1" isSynced="0"] MSG=device started ``` -## Self-check (vs measurements/tcp.csv) +## Self-check (vs measurements/time-quality.csv) ```text - OK flash_text: 357140 (expected 357140, Δ0) - OK flash_data: 488 (expected 488, Δ0) - OK static_bss: 116560 (expected 116560, Δ0) + OK flash_text: 357424 (expected 357424, Δ0) + OK flash_data: 496 (expected 496, Δ0) + OK static_bss: 116576 (expected 116576, Δ0) OK heap_used: 4440 (expected 4440, Δ0) - OK mbedtls_peak: 21328 (expected 21328, Δ0) - OK mbedtls_free: 11440 (expected 11440, Δ0) + OK mbedtls_peak: 21352 (expected 21352, Δ0) + OK mbedtls_free: 11416 (expected 11416, Δ0) OK lwip_mem_free: 7576 (expected 7576, Δ0) OK lwip_pbufs_free: 13 (expected 13, Δ0) OK stack_log: 568 (expected 568, Δ0)