diff --git a/src/ESPNetwork.cpp b/src/ESPNetwork.cpp index 9925420..b8e9b83 100644 --- a/src/ESPNetwork.cpp +++ b/src/ESPNetwork.cpp @@ -28,6 +28,7 @@ extern MqttConnection mqtt; extern rebootDelay_t rebootDelay; extern ESPNetwork net; extern SomfyShadeController somfy; +extern LoopStats loopStats; static unsigned long _lastHeapEmit = 0; @@ -680,8 +681,15 @@ void ESPNetwork::emitHeap(uint8_t num) { json->addElem("min", minHeap); json->addElem("total", ESP.getHeapSize()); json->addElem("uptime", (uint64_t)millis()); + // The window in progress. Only a broadcast closes it, so a client + // connecting doesn't wipe a slow pass before Home Assistant has seen it. + json->addElem("loopRate", loopStats.rate(millis())); + json->addElem("loopMaxUs", loopStats.maxUs()); json->endObject(); if(target == heap_emit_t::room) sockEmit.endEmitRoom(0); else sockEmit.endEmit(num); - if(target == heap_emit_t::broadcast) _lastHeapEmit = millis(); + if(target == heap_emit_t::broadcast) { + _lastHeapEmit = millis(); + loopStats.publish(_lastHeapEmit); + } } diff --git a/src/SomfyController.ino b/src/SomfyController.ino index 718d602..fb1dbc2 100644 --- a/src/SomfyController.ino +++ b/src/SomfyController.ino @@ -41,6 +41,7 @@ SomfyShadeOps shadeOps; ShadeRequests shadeRequests(shadeOps); LoopQueue loopQueue; SnapshotSlots snapshotSlots; +LoopStats loopStats; uint32_t oldheap = 0; @@ -141,6 +142,9 @@ void setup() { void loop() { // put your main code here, to run repeatedly: //uint32_t heap = ESP.getFreeHeap(); + // Times the whole pass for memStatus, including any time the loop task was + // pre-empted, since that delays the loop too. + ElapsedTimer pass; if(rebootDelay.reboot && millis() > rebootDelay.rebootTime) { ESP_LOGI(TAG, "Rebooting after %lums", rebootDelay.rebootTime); net.end(); @@ -180,4 +184,5 @@ void loop() { ESP.restart(); } esp_task_wdt_reset(); + loopStats.record(pass.us()); } diff --git a/src/Utils.cpp b/src/Utils.cpp index 0d1691b..98c1b88 100644 --- a/src/Utils.cpp +++ b/src/Utils.cpp @@ -152,3 +152,20 @@ heap_emit_t heapEmitTarget(uint8_t num, uint32_t sinceLastMs, uint32_t intervalM if(sinceLastMs >= intervalMs) return heap_emit_t::broadcast; return roomHasClients ? heap_emit_t::room : heap_emit_t::none; } +void LoopStats::record(uint32_t passUs) { + _passes++; + if(passUs > _maxUs) _maxUs = passUs; +} +uint32_t LoopStats::rate(uint32_t nowMs) const { + // The unsigned subtraction keeps the window right across a millis() wrap. + const uint32_t elapsedMs = nowMs - _startMs; + if(elapsedMs == 0) return 0; + return (uint32_t)((uint64_t)_passes * 1000 / elapsedMs); +} +void LoopStats::publish(uint32_t nowMs) { + _publishedRate.store(this->rate(nowMs), std::memory_order_relaxed); + _publishedMaxUs.store(_maxUs, std::memory_order_relaxed); + _passes = 0; + _maxUs = 0; + _startMs = nowMs; +} diff --git a/src/Utils.h b/src/Utils.h index b721c5f..e72e3c0 100644 --- a/src/Utils.h +++ b/src/Utils.h @@ -1,6 +1,7 @@ #ifndef utils_h #define utils_h #include +#include #define DEBUG_SOMFY Serial @@ -78,6 +79,26 @@ enum class heap_emit_t : uint8_t { none, client, broadcast, room }; // num is the socket client asked for, 255 for everyone. A broadcast goes out // every intervalMs; in between only the clients in room 0 get one. heap_emit_t heapEmitTarget(uint8_t num, uint32_t sinceLastMs, uint32_t intervalMs, bool roomHasClients); +// How well loop() keeps up: the passes it made per second and its longest +// pass, over the window since the last memStatus broadcast. Only the loop +// task calls record(), rate(), maxUs() and publish(). publish() closes the +// window and keeps its figures where another task (the /discovery response) +// can read them without seeing a half reset window. +class LoopStats { + uint32_t _passes = 0; + uint32_t _maxUs = 0; + uint32_t _startMs = 0; + std::atomic _publishedRate{0}; + std::atomic _publishedMaxUs{0}; + public: + void record(uint32_t passUs); + // Passes per second since the window started, 0 for an empty window. + uint32_t rate(uint32_t nowMs) const; + uint32_t maxUs() const { return _maxUs; } + void publish(uint32_t nowMs); + uint32_t publishedRate() const { return _publishedRate.load(std::memory_order_relaxed); } + uint32_t publishedMaxUs() const { return _publishedMaxUs.load(std::memory_order_relaxed); } +}; class Timestamp { char _timeBuffer[128]; diff --git a/src/entryPoints/Web.cpp b/src/entryPoints/Web.cpp index cbf58a9..f84634f 100644 --- a/src/entryPoints/Web.cpp +++ b/src/entryPoints/Web.cpp @@ -28,6 +28,7 @@ extern ConfigSettings settings; extern SSDPClass SSDP; extern rebootDelay_t rebootDelay; +extern LoopStats loopStats; extern SomfyShadeController somfy; extern Web webServer; extern MqttConnection mqtt; @@ -276,6 +277,10 @@ static void discoveryHeader(JsonFormatter &json, const model_snapshot_t &snap) { json.addElem("min", ESP.getMinFreeHeap()); json.addElem("total", ESP.getHeapSize()); json.addElem("uptime", (uint64_t)millis()); + // This runs on the web server's task, so it reports the last window the + // loop task closed rather than reading the one it is still filling. + json.addElem("loopRate", loopStats.publishedRate()); + json.addElem("loopMaxUs", loopStats.publishedMaxUs()); json.endObject(); } diff --git a/test/test_utils/test_utils.cpp b/test/test_utils/test_utils.cpp index 80e76cd..8d21b54 100644 --- a/test/test_utils/test_utils.cpp +++ b/test/test_utils/test_utils.cpp @@ -272,6 +272,64 @@ static void test_heapEmitTarget_broadcasts_once_per_interval() { static void test_heapEmitTarget_room_in_between() { TEST_ASSERT_TRUE(heap_emit_t::room == heapEmitTarget(255, 1000, 30000, true)); } + +/********************************************************************* + * LoopStats + ********************************************************************/ +static void test_loopStats_rate_is_passes_per_second() { + LoopStats stats; + for(int i = 0; i < 4500; i++) stats.record(100); + TEST_ASSERT_EQUAL_UINT32(1500, stats.rate(3000)); +} +static void test_loopStats_empty_window_has_no_rate() { + LoopStats stats; + stats.record(100); + TEST_ASSERT_EQUAL_UINT32(0, stats.rate(0)); +} +static void test_loopStats_keeps_the_longest_pass() { + LoopStats stats; + stats.record(120); + stats.record(4800); + stats.record(90); + TEST_ASSERT_EQUAL_UINT32(4800, stats.maxUs()); +} +static void test_loopStats_nothing_published_before_the_first_window() { + LoopStats stats; + stats.record(4800); + TEST_ASSERT_EQUAL_UINT32(0, stats.publishedRate()); + TEST_ASSERT_EQUAL_UINT32(0, stats.publishedMaxUs()); +} +static void test_loopStats_publish_keeps_the_window_and_starts_a_new_one() { + LoopStats stats; + for(int i = 0; i < 300; i++) stats.record(100); + stats.record(4800); + stats.publish(1000); + TEST_ASSERT_EQUAL_UINT32(301, stats.publishedRate()); + TEST_ASSERT_EQUAL_UINT32(4800, stats.publishedMaxUs()); + TEST_ASSERT_EQUAL_UINT32(0, stats.rate(1000)); + TEST_ASSERT_EQUAL_UINT32(0, stats.maxUs()); + for(int i = 0; i < 50; i++) stats.record(200); + // The new window started at the publish, not at boot. + TEST_ASSERT_EQUAL_UINT32(100, stats.rate(1500)); + TEST_ASSERT_EQUAL_UINT32(200, stats.maxUs()); + TEST_ASSERT_EQUAL_UINT32(301, stats.publishedRate()); +} +static void test_loopStats_reading_does_not_reset_the_window() { + LoopStats stats; + stats.record(4800); + (void)stats.rate(500); + (void)stats.maxUs(); + stats.record(100); + TEST_ASSERT_EQUAL_UINT32(4800, stats.maxUs()); + TEST_ASSERT_EQUAL_UINT32(2, stats.rate(1000)); +} +static void test_loopStats_window_across_millis_wrap() { + LoopStats stats; + stats.publish(0xFFFFFE00); + for(int i = 0; i < 1024; i++) stats.record(100); + // 0x200 ms before the wrap plus 0x200 after it is 1024 ms. + TEST_ASSERT_EQUAL_UINT32(1000, stats.rate(0x00000200)); +} int main(int argc, char **argv) { (void)argc; (void)argv; @@ -314,5 +372,12 @@ int main(int argc, char **argv) { RUN_TEST(test_heapEmitTarget_one_client_always_gets_it); RUN_TEST(test_heapEmitTarget_broadcasts_once_per_interval); RUN_TEST(test_heapEmitTarget_room_in_between); + RUN_TEST(test_loopStats_rate_is_passes_per_second); + RUN_TEST(test_loopStats_empty_window_has_no_rate); + RUN_TEST(test_loopStats_keeps_the_longest_pass); + RUN_TEST(test_loopStats_nothing_published_before_the_first_window); + RUN_TEST(test_loopStats_publish_keeps_the_window_and_starts_a_new_one); + RUN_TEST(test_loopStats_reading_does_not_reset_the_window); + RUN_TEST(test_loopStats_window_across_millis_wrap); return UNITY_END(); }