From ecc24bfd71448790f5eb31ee2b7118b9a122cb9d Mon Sep 17 00:00:00 2001 From: Bimal Gaudel Date: Mon, 11 May 2026 12:19:34 -0400 Subject: [PATCH 1/6] feature: log per-op left/right/result memory and cache high-water mark --- SeQuant/core/eval/cache_manager.hpp | 13 ++++- SeQuant/core/eval/eval.hpp | 73 +++++++++++++++++++++++++++-- 2 files changed, 79 insertions(+), 7 deletions(-) diff --git a/SeQuant/core/eval/cache_manager.hpp b/SeQuant/core/eval/cache_manager.hpp index 6ce8f54b2e..f1185dce36 100644 --- a/SeQuant/core/eval/cache_manager.hpp +++ b/SeQuant/core/eval/cache_manager.hpp @@ -83,8 +83,9 @@ class CacheManager { std::unordered_map cache_map_; public: - template - explicit CacheManager(Iterable1&& decaying) noexcept { + template + requires(!std::same_as, CacheManager>) + explicit CacheManager(Iterable&& decaying) noexcept { for (auto&& [k, c] : decaying) cache_map_.try_emplace(k, entry{c}); } @@ -145,6 +146,14 @@ class CacheManager { return iter == end ? -1 : static_cast(iter->second.max_life_count()); } + /// \return true iff the key is registered for caching and currently holds + /// stored data (i.e. has been stored and not yet drained by its + /// final access). + [[nodiscard]] bool alive(key_type const& key) const noexcept { + auto iter = cache_map_.find(key); + return iter != cache_map_.end() && iter->second.alive(); + } + /// /// \return The number of entries with life_count greater than zero. /// diff --git a/SeQuant/core/eval/eval.hpp b/SeQuant/core/eval/eval.hpp index db7e02020f..07c3b5c4c7 100644 --- a/SeQuant/core/eval/eval.hpp +++ b/SeQuant/core/eval/eval.hpp @@ -110,6 +110,21 @@ struct EvalStat { Bytes memory; }; +struct EvalDetailBinary { + EvalMode mode; + Duration time; + Bytes mem_left; + Bytes mem_right; + Bytes mem_result; + Bytes mem_hwmark; +}; + +struct CacheDetail { + CacheMode mode; + size_t key; + Bytes memory; +}; + struct CacheStat { CacheMode mode; size_t key; @@ -133,6 +148,27 @@ auto eval(EvalStat const& stat, Args const&... args) { args...); } +template +auto eval(EvalDetailBinary const& stat, Args const&... args) { + log("EvalDetail", // + to_string(stat.mode), // + stat.time, // + std::format("left={}", to_string(stat.mem_left)), // + std::format("right={}", to_string(stat.mem_right)), // + std::format("result={}", to_string(stat.mem_result)), // + std::format("hw={}", to_string(stat.mem_hwmark)), // + args...); +} + +template +auto cache(CacheDetail const& stat, Args const&... args) { + log("CacheDetail", // + to_string(stat.mode), // + stat.key, // + to_string(stat.memory), // + args...); +} + template auto cache(CacheStat const& stat, Args const&... args) { log("Cache", // @@ -278,14 +314,28 @@ ResultPtr evaluate(Node const& node, // }; if (auto ptr = cache.access(node); ptr) { - if constexpr (trace(EvalTrace)) log::cache(node, cache); + if constexpr (trace(EvalTrace)) { + log::cache(node, cache); + log::cache(log::CacheDetail{.mode = cache.life(node) == 0 + ? log::CacheMode::Release + : log::CacheMode::Access, + .key = node->hash_value(), + .memory = log::bytes(ptr)}, + log::label(node)); + } return mult_by_phase(ptr); } else if (cache.exists(node)) { auto ptr = cache.store( node, mult_by_phase(evaluate( node, le, cache))); - if constexpr (trace(EvalTrace)) log::cache(node, cache); + if constexpr (trace(EvalTrace)) { + log::cache(node, cache); + log::cache(log::CacheDetail{.mode = log::CacheMode::Store, + .key = node->hash_value(), + .memory = log::bytes(ptr)}, + log::label(node)); + } return mult_by_phase(ptr); } else { @@ -326,12 +376,25 @@ ResultPtr evaluate(Node const& node, // // logging if constexpr (trace(EvalTrace)) { - auto stat = + log::eval( log::EvalStat{.mode = log::eval_mode(node), .time = time, .memory = node.leaf() ? log::bytes(result) - : log::bytes(left, right, result)}; - log::eval(stat, log::label(node)); + : log::bytes(left, right, result)}, + log::label(node)); + + if (!node.leaf()) { + auto hwmark = log::bytes(cache) + log::bytes(result).value; + if (!cache.alive(node.left())) hwmark += log::bytes(left).value; + if (!cache.alive(node.right())) hwmark += log::bytes(right).value; + auto stat = log::EvalDetailBinary{.mode = log::eval_mode(node), + .time = time, + .mem_left = log::bytes(left), + .mem_right = log::bytes(right), + .mem_result = log::bytes(result), + .mem_hwmark = {hwmark}}; + log::eval(stat, log::label(node)); + } } return result; From 1c95f60304474ff443ecfc5035a25e7b23d231a7 Mon Sep 17 00:00:00 2001 From: Bimal Gaudel Date: Tue, 12 May 2026 10:58:34 -0400 Subject: [PATCH 2/6] refactor: unify eval log format and add cache liveness queries --- SeQuant/core/eval/cache_manager.hpp | 7 +++ SeQuant/core/eval/eval.hpp | 82 +++++++++++------------------ tests/unit/test_cache_manager.cpp | 48 +++++++++++++++++ 3 files changed, 86 insertions(+), 51 deletions(-) diff --git a/SeQuant/core/eval/cache_manager.hpp b/SeQuant/core/eval/cache_manager.hpp index f1185dce36..52dbe4657c 100644 --- a/SeQuant/core/eval/cache_manager.hpp +++ b/SeQuant/core/eval/cache_manager.hpp @@ -154,6 +154,13 @@ class CacheManager { return iter != cache_map_.end() && iter->second.alive(); } + /// \return size in bytes of the data currently held for @p key, or 0 if + /// the key is not registered or no data is currently stored. + [[nodiscard]] size_t entry_size_in_bytes(key_type const& key) const noexcept { + auto iter = cache_map_.find(key); + return iter == cache_map_.end() ? 0 : iter->second.size_in_bytes(); + } + /// /// \return The number of entries with life_count greater than zero. /// diff --git a/SeQuant/core/eval/eval.hpp b/SeQuant/core/eval/eval.hpp index 07c3b5c4c7..ea6fa1d5aa 100644 --- a/SeQuant/core/eval/eval.hpp +++ b/SeQuant/core/eval/eval.hpp @@ -33,15 +33,15 @@ struct Bytes { size_t value; }; -template - requires((std::same_as && ...)) -[[nodiscard]] auto bytes(T const&... args) { - return Bytes{(args->size_in_bytes() + ...)}; -} - -template -[[nodiscard]] inline auto bytes(CacheManager const& cman) { - return cman.size_in_bytes(); +template +[[nodiscard]] inline auto bytes(T const& arg, Ts const&... args) { + auto one = [](auto const& a) -> size_t { + if constexpr (requires { a->size_in_bytes(); }) + return a->size_in_bytes(); + else + return a.size_in_bytes(); + }; + return Bytes{(one(arg) + ... + one(args))}; } [[nodiscard]] inline auto to_string(Bytes bs) noexcept { @@ -119,18 +119,13 @@ struct EvalDetailBinary { Bytes mem_hwmark; }; -struct CacheDetail { - CacheMode mode; - size_t key; - Bytes memory; -}; - struct CacheStat { CacheMode mode; size_t key; int curr_life, max_life; size_t num_alive; - Bytes memory; + Bytes entry_memory; + Bytes total_memory; }; template @@ -160,23 +155,15 @@ auto eval(EvalDetailBinary const& stat, Args const&... args) { args...); } -template -auto cache(CacheDetail const& stat, Args const&... args) { - log("CacheDetail", // - to_string(stat.mode), // - stat.key, // - to_string(stat.memory), // - args...); -} - template auto cache(CacheStat const& stat, Args const&... args) { - log("Cache", // - to_string(stat.mode), // - stat.key, // - std::format("{}/{}", stat.curr_life, stat.max_life), // - stat.num_alive, // - to_string(stat.memory), // + log("Cache", // + to_string(stat.mode), // + std::format("key={}", stat.key), // + std::format("life={}/{}", stat.curr_life, stat.max_life), // + std::format("alive={}", stat.num_alive), // + std::format("entry={}", to_string(stat.entry_memory)), // + std::format("total={}", to_string(stat.total_memory)), // args...); } @@ -197,7 +184,8 @@ auto cache(N const& node, CacheManager& cm, Args const&... args) { .curr_life = cur_l, .max_life = max_l, .num_alive = cm.alive_count(), - .memory = {bytes(cm)}}, + .entry_memory = {cm.entry_size_in_bytes(node)}, + .total_memory = {bytes(cm)}}, args...); } @@ -314,28 +302,14 @@ ResultPtr evaluate(Node const& node, // }; if (auto ptr = cache.access(node); ptr) { - if constexpr (trace(EvalTrace)) { - log::cache(node, cache); - log::cache(log::CacheDetail{.mode = cache.life(node) == 0 - ? log::CacheMode::Release - : log::CacheMode::Access, - .key = node->hash_value(), - .memory = log::bytes(ptr)}, - log::label(node)); - } + if constexpr (trace(EvalTrace)) log::cache(node, cache, log::label(node)); return mult_by_phase(ptr); } else if (cache.exists(node)) { auto ptr = cache.store( node, mult_by_phase(evaluate( node, le, cache))); - if constexpr (trace(EvalTrace)) { - log::cache(node, cache); - log::cache(log::CacheDetail{.mode = log::CacheMode::Store, - .key = node->hash_value(), - .memory = log::bytes(ptr)}, - log::label(node)); - } + if constexpr (trace(EvalTrace)) log::cache(node, cache, log::label(node)); return mult_by_phase(ptr); } else { @@ -384,9 +358,15 @@ ResultPtr evaluate(Node const& node, // log::label(node)); if (!node.leaf()) { - auto hwmark = log::bytes(cache) + log::bytes(result).value; - if (!cache.alive(node.left())) hwmark += log::bytes(left).value; - if (!cache.alive(node.right())) hwmark += log::bytes(right).value; + // A cached child is *distinct* from the local left/right when its + // canon_phase != 1, because mult_by_phase allocates a fresh buffer + // while the cache still holds the pre-phase data. So only skip the + // local's bytes when the cache aliases the same buffer (phase == 1). + size_t hwmark = log::bytes(cache).value + log::bytes(result).value; + if (!cache.alive(node.left()) || node.left()->canon_phase() != 1) + hwmark += log::bytes(left).value; + if (!cache.alive(node.right()) || node.right()->canon_phase() != 1) + hwmark += log::bytes(right).value; auto stat = log::EvalDetailBinary{.mode = log::eval_mode(node), .time = time, .mem_left = log::bytes(left), diff --git a/tests/unit/test_cache_manager.cpp b/tests/unit/test_cache_manager.cpp index cf66102630..51a9a3acfe 100644 --- a/tests/unit/test_cache_manager.cpp +++ b/tests/unit/test_cache_manager.cpp @@ -111,6 +111,54 @@ TEST_CASE("cache_manager", "[cache_manager]") { } } + SECTION("alive and entry_size_in_bytes") { + auto man = man_const; + + // A key never registered in the manager. + auto const stray = make_node(L"R = B"); + REQUIRE_FALSE(man.exists(stray)); + REQUIRE_FALSE(man.alive(stray)); + REQUIRE(man.entry_size_in_bytes(stray) == 0); + + // Registered but never stored: not alive, zero size. + for (auto&& k : decaying_keys) { + REQUIRE(man.exists(k)); + REQUIRE_FALSE(man.alive(k)); + REQUIRE(man.entry_size_in_bytes(k) == 0); + } + + // After store(): alive, size matches the stored data. + for (auto&& [k, v] : zip(decaying_keys, decaying_vals)) { + REQUIRE(man.store(k, v)); + REQUIRE(man.alive(k)); + REQUIRE(man.entry_size_in_bytes(k) == v->size_in_bytes()); + } + + // Drain each entry's remaining life. store() consumed one access already, + // so r - 1 accesses remain before data_p is moved out. + for (auto&& [k, r] : zip(decaying_keys, decaying_repeats)) { + for (auto i = r - 1; i > 0; --i) { + REQUIRE(man.alive(k)); // still holds data before this access + REQUIRE(man.access(k)); + } + // Final access has drained life to 0 and moved data_p out. + REQUIRE_FALSE(man.alive(k)); + REQUIRE(man.entry_size_in_bytes(k) == 0); + } + + // reset() restores life counts; re-store, confirm alive, then reset() + // and confirm entries are not-alive again. + man.reset(); + for (auto&& [k, v] : zip(decaying_keys, decaying_vals)) + REQUIRE(man.store(k, v)); + for (auto&& k : decaying_keys) REQUIRE(man.alive(k)); + man.reset(); + for (auto&& k : decaying_keys) { + REQUIRE_FALSE(man.alive(k)); + REQUIRE(man.entry_size_in_bytes(k) == 0); + } + } + SECTION("Hash collision safety") { // Two structurally different nodes auto const n1 = make_node(L"R{a1;i1} = f{a1;i1}"); From f31ddaa725c987eab8b1d8d93604ae4dfe2b72bd Mon Sep 17 00:00:00 2001 From: Bimal Gaudel Date: Tue, 12 May 2026 14:33:21 -0400 Subject: [PATCH 3/6] refactor: unify per-op Eval log record and tighten high-water mark MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Drop EvalDetailBinary; collapse to a single Eval line per op, with optional left/right populated only for Sum/Product. Add an alloc field that distinguishes fresh-allocation ops from SumInplace (alloc=0B), so summing the column gives total bytes allocated and `grep alloc=0B` isolates inplace ops. Fix hwmark undercounts in Permute and SumInplace for cached inputs whose canon_phase != 1 or that the permute wrapper turned into a fresh buffer — previously these silently biased hw down. --- SeQuant/core/eval/eval.hpp | 160 +++++++++++++++++++++++++------------ 1 file changed, 111 insertions(+), 49 deletions(-) diff --git a/SeQuant/core/eval/eval.hpp b/SeQuant/core/eval/eval.hpp index ea6fa1d5aa..6e31bc09fc 100644 --- a/SeQuant/core/eval/eval.hpp +++ b/SeQuant/core/eval/eval.hpp @@ -20,6 +20,7 @@ #include #include +#include #include #include @@ -104,19 +105,45 @@ enum struct TermMode { Begin, End }; return (mode == TermMode::Begin) ? "Begin" : "End"; } +/// One log record per eval op. Line format: +/// +// clang-format off +/// Eval | |