Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
17 changes: 17 additions & 0 deletions CHANGELOG.md
Original file line number Diff line number Diff line change
Expand Up @@ -13,6 +13,23 @@ commit messages only.

## [Unreleased]

### Added

- Real per-device health (#87): `DeviceHealth.last_seen` is now the wall-clock
time of the last successful CRUMBS operation against the device's address
(probes included), and three new per-device metrics expose the session's
cumulative I/O counters — `io_ok`, `io_failed`, and `io_retried_attempts`.
The retry counter records every attempt beyond an operation's first, so
intermittent bus trouble that the retry policy masks stays visible in health
output instead of silently disappearing (the mechanism that hid a ~30%
per-transaction failure rate for weeks, see feastorg/Slice_DCMT#3).

### Changed

- `last_seen` is no longer fabricated: devices with no successful contact yet
(including missing-expected devices) leave it unset, replacing the previous
provider-start-time constant stamped on every device.

## [0.3.2] - 2026-07-14

### Changed
Expand Down
22 changes: 17 additions & 5 deletions src/core/bread_provider_runtime.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -8,6 +8,7 @@
#include "anolis/provider_sdk/result.hpp"
#include "config/provider_config.hpp"
#include "core/runtime_state.hpp"
#include "crumbs/session.hpp"
#include "devices/common/device_adapter.hpp"
#include "devices/common/inventory.hpp"
#include "protocol.pb.h"
Expand Down Expand Up @@ -83,26 +84,37 @@ sdk::ReadinessReport BreadProviderRuntime::readiness() const {
}

sdk::DeviceHealthExtra BreadProviderRuntime::device_health(const std::string& device_id) const {
// Restore bread's pre-migration per-device health (SDK#9) from one snapshot.
// last_seen is the startup constant to_timestamp(started_at) — bread has no real
// per-device heartbeat yet (tracked in anolis-provider-bread#87).
// Per-device health (#87): last_seen is the wall-clock time of the last
// successful CRUMBS operation against the device's address, and the io_*
// metrics expose the session's cumulative counters — including retries
// that eventually succeeded, so intermittent bus trouble is visible here
// instead of hiding behind the retry policy.
const runtime::RuntimeState state = runtime::snapshot();
sdk::DeviceHealthExtra extra;
if (const inventory::InventoryDevice* device = inventory::find_device(state.devices, device_id)) {
extra.metrics["address"] = device->descriptor.address();
extra.metrics["type_id"] = device->descriptor.type_id();
extra.metrics["inventory"] = state.inventory_mode;
extra.last_seen = to_timestamp(state.started_at);
if (crumbs::Session* session = runtime::session()) {
const crumbs::AddressStats stats = session->stats_for(static_cast<uint8_t>(device->address));
extra.metrics["io_ok"] = std::to_string(stats.ok);
extra.metrics["io_failed"] = std::to_string(stats.failed);
extra.metrics["io_retried_attempts"] = std::to_string(stats.retried_attempts);
if (stats.has_success) {
extra.last_seen = to_timestamp(stats.last_success);
}
}
// No successful contact yet -> last_seen stays unset (never fabricated).
return extra;
}
// Missing-expected devices surface on get_health (readiness() maps them to
// failed_devices); they are NOT in the live inventory, so branch on the
// missing-expected set rather than a find_device lookup (which returns null).
// There has been no contact with a missing device, so last_seen stays unset.
for (const auto& missing_id : state.missing_expected_ids) {
if (missing_id == device_id) {
extra.metrics["inventory"] = state.inventory_mode;
extra.metrics["missing"] = "true";
extra.last_seen = to_timestamp(state.started_at);
break;
}
}
Expand Down
40 changes: 34 additions & 6 deletions src/crumbs/session.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -136,7 +136,10 @@ SessionStatus Session::send(uint8_t address, const RawFrame &frame) {
return SessionStatus::failure(SessionErrorCode::NotOpen, "CRUMBS session is not open");
}

return execute_with_retry(options_, "send", address, [&]() { return transport_.send(address, frame); });
SessionStatus status =
execute_with_retry(options_, "send", address, [&]() { return transport_.send(address, frame); });
record_outcome(address, status);
return status;
}

SessionStatus Session::read(uint8_t address, RawFrame &frame) {
Expand All @@ -152,7 +155,10 @@ SessionStatus Session::read(uint8_t address, RawFrame &frame) {

const uint32_t timeout_us = options_.timeout_ms > (UINT32_MAX / 1000u) ? UINT32_MAX : options_.timeout_ms * 1000u;

return execute_with_retry(options_, "read", address, [&]() { return transport_.read(address, frame, timeout_us); });
SessionStatus status =
execute_with_retry(options_, "read", address, [&]() { return transport_.read(address, frame, timeout_us); });
record_outcome(address, status);
return status;
}

SessionStatus Session::query_read(uint8_t address, uint8_t reply_opcode, RawFrame &out) {
Expand All @@ -175,15 +181,37 @@ SessionStatus Session::query_read(uint8_t address, uint8_t reply_opcode, RawFram

// Hold the session lock across send → delay → read so the SET_REPLY query
// sequence cannot interleave with another caller on the shared bus.
return execute_with_retry(options_, "query_read", address, [&]() {
SessionStatus status = transport_.send(address, query);
if (!status) {
return status;
SessionStatus status = execute_with_retry(options_, "query_read", address, [&]() {
SessionStatus attempt = transport_.send(address, query);
if (!attempt) {
return attempt;
}

transport_.delay_us(options_.query_delay_us);
return transport_.read(address, out, timeout_us);
});
record_outcome(address, status);
return status;
}

AddressStats Session::stats_for(uint8_t address) const {
std::lock_guard<std::mutex> lock(mutex_);
const auto it = stats_.find(address);
return it == stats_.end() ? AddressStats{} : it->second;
}

void Session::record_outcome(uint8_t address, const SessionStatus &status) {
AddressStats &stats = stats_[address];
if (status.attempts > 1) {
stats.retried_attempts += static_cast<uint64_t>(status.attempts - 1);
}
if (status.ok()) {
++stats.ok;
stats.has_success = true;
stats.last_success = std::chrono::system_clock::now();
} else {
++stats.failed;
}
}

SessionStatus Session::validate_open_options() const {
Expand Down
35 changes: 35 additions & 0 deletions src/crumbs/session.hpp
Original file line number Diff line number Diff line change
Expand Up @@ -6,8 +6,10 @@
* provider.
*/

#include <chrono>
#include <cstddef>
#include <cstdint>
#include <map>
#include <mutex>
#include <string>
#include <vector>
Expand Down Expand Up @@ -88,6 +90,25 @@ struct ScanResult {
uint8_t type_id = 0;
};

/**
* @brief Cumulative per-address I/O statistics kept by `Session`.
*
* Counters are attempt-aware: `retried_attempts` counts every attempt beyond
* an operation's first, so failures that a later retry masks stay visible in
* health output instead of disappearing into a success. Only operations that
* reached the transport are counted; argument/state validation failures are
* not I/O.
*/
struct AddressStats {
uint64_t ok = 0;
uint64_t failed = 0;
uint64_t retried_attempts = 0;
bool has_success = false;
/** @brief Wall-clock time of the last successful operation; meaningful only
* when `has_success` is true. */
std::chrono::system_clock::time_point last_success{};
};

/**
* @brief Session-level transport options derived from provider config.
*/
Expand Down Expand Up @@ -184,15 +205,29 @@ class Session {
*/
SessionStatus query_read(uint8_t address, uint8_t reply_opcode, RawFrame &out);

/**
* @brief Return a copy of the cumulative I/O statistics for one address.
*
* Feeds per-device health (`DeviceHealth.last_seen` and the io_* metrics,
* anolis-provider-bread#87). Returns zeroed stats for an address this
* session has never performed I/O against.
*/
AddressStats stats_for(uint8_t address) const;

private:
SessionStatus validate_open_options() const;
SessionStatus validate_scan_options(const ScanOptions &options) const;
SessionStatus validate_address(uint8_t address) const;
SessionStatus validate_frame(const RawFrame &frame) const;

/** @brief Record one completed transport operation. Caller must hold
* `mutex_`. */
void record_outcome(uint8_t address, const SessionStatus &status);

Transport &transport_;
SessionOptions options_;
mutable std::mutex mutex_;
std::map<uint8_t, AddressStats> stats_;
};

/** @brief Build session transport options from resolved provider config. */
Expand Down
96 changes: 96 additions & 0 deletions tests/unit/crumbs_session_test.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -209,5 +209,101 @@ TEST(CrumbsSessionTest, RejectsOversizedPayloadBeforeTransportCall) {
EXPECT_EQ(transport.send_calls, 0);
}

// ---------------------------------------------------------------------------
// Per-address I/O statistics (#87) — the counters behind DeviceHealth.
// ---------------------------------------------------------------------------

TEST(CrumbsSessionStats, SuccessSetsLastSeenAndCountsOk) {
FakeTransport transport;
Session session(transport, SessionOptions{"/dev/i2c-1", 10000u, 100u, 2});
ASSERT_TRUE(session.open());

// Never-contacted address starts zeroed with no last_success.
AddressStats before = session.stats_for(0x08u);
EXPECT_EQ(before.ok, 0U);
EXPECT_FALSE(before.has_success);

transport.read_actions.push_back({SessionStatus::success(), RawFrame{0x01, 0x80, {0x11}}});
RawFrame reply;
ASSERT_TRUE(session.query_read(0x08u, 0x80u, reply));

const AddressStats after = session.stats_for(0x08u);
EXPECT_EQ(after.ok, 1U);
EXPECT_EQ(after.failed, 0U);
EXPECT_EQ(after.retried_attempts, 0U);
EXPECT_TRUE(after.has_success);
EXPECT_GT(after.last_success.time_since_epoch().count(), 0);
}

TEST(CrumbsSessionStats, MaskedRetryStaysVisibleInRetriedAttempts) {
FakeTransport transport;
Session session(transport, SessionOptions{"/dev/i2c-1", 10000u, 100u, 2});
ASSERT_TRUE(session.open());

// Attempt 1 fails on the wire, attempt 2 succeeds — the operation reports
// success, but the flakiness must not vanish from the stats.
transport.send_actions.push_back(SessionStatus::failure(SessionErrorCode::WriteFailed, "temporary NACK"));
transport.send_actions.push_back(SessionStatus::success());
transport.read_actions.push_back({SessionStatus::success(), RawFrame{0x01, 0x80, {0x11}}});

RawFrame reply;
ASSERT_TRUE(session.query_read(0x08u, 0x80u, reply));

const AddressStats stats = session.stats_for(0x08u);
EXPECT_EQ(stats.ok, 1U);
EXPECT_EQ(stats.failed, 0U);
EXPECT_EQ(stats.retried_attempts, 1U);
EXPECT_TRUE(stats.has_success);
}

TEST(CrumbsSessionStats, ExhaustedRetriesCountOneFailure) {
FakeTransport transport;
Session session(transport, SessionOptions{"/dev/i2c-1", 10000u, 100u, 1});
ASSERT_TRUE(session.open());

transport.send_actions.push_back(SessionStatus::failure(SessionErrorCode::WriteFailed, "NACK"));
transport.send_actions.push_back(SessionStatus::failure(SessionErrorCode::WriteFailed, "NACK"));

RawFrame frame{0x01, 0x02, {0xAA}};
EXPECT_FALSE(session.send(0x08u, frame));

const AddressStats stats = session.stats_for(0x08u);
EXPECT_EQ(stats.ok, 0U);
EXPECT_EQ(stats.failed, 1U);
EXPECT_EQ(stats.retried_attempts, 1U);
EXPECT_FALSE(stats.has_success);
}

TEST(CrumbsSessionStats, ValidationFailuresAreNotIo) {
FakeTransport transport;
Session session(transport, SessionOptions{"/dev/i2c-1", 10000u, 100u, 1});
ASSERT_TRUE(session.open());

RawFrame oversized;
oversized.payload.resize(kMaxPayloadBytes + 1u, 0xAAu);
EXPECT_FALSE(session.send(0x08u, oversized));

const AddressStats stats = session.stats_for(0x08u);
EXPECT_EQ(stats.ok, 0U);
EXPECT_EQ(stats.failed, 0U);
}

TEST(CrumbsSessionStats, StatsAreTrackedPerAddress) {
FakeTransport transport;
Session session(transport, SessionOptions{"/dev/i2c-1", 10000u, 100u, 1});
ASSERT_TRUE(session.open());

RawFrame frame{0x01, 0x02, {0xAA}};
ASSERT_TRUE(session.send(0x08u, frame));
transport.send_actions.push_back(SessionStatus::failure(SessionErrorCode::WriteFailed, "NACK"));
transport.send_actions.push_back(SessionStatus::failure(SessionErrorCode::WriteFailed, "NACK"));
EXPECT_FALSE(session.send(0x09u, frame));

EXPECT_EQ(session.stats_for(0x08u).ok, 1U);
EXPECT_EQ(session.stats_for(0x08u).failed, 0U);
EXPECT_EQ(session.stats_for(0x09u).ok, 0U);
EXPECT_EQ(session.stats_for(0x09u).failed, 1U);
}

} // namespace
} // namespace anolis_provider_bread::crumbs
35 changes: 33 additions & 2 deletions tests/unit/shell_test.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -332,7 +332,12 @@ TEST(ShellTest, SupportsHelloInventoryAndHealth) {
EXPECT_EQ(rlht_health->metrics().at("type_id"), "bread.rlht");
EXPECT_EQ(rlht_health->metrics().at("inventory"), "config_seeded");
EXPECT_FALSE(rlht_health->metrics().at("address").empty());
EXPECT_TRUE(rlht_health->has_last_seen());
// #87: last_seen is a real contact timestamp now. Config-seeded mock
// inventory has had NO device I/O yet, so it must be unset (never the
// old started_at fabrication), and the io counters must read zero.
EXPECT_FALSE(rlht_health->has_last_seen());
EXPECT_EQ(rlht_health->metrics().at("io_ok"), "0");
EXPECT_EQ(rlht_health->metrics().at("io_failed"), "0");
}

{
Expand Down Expand Up @@ -370,7 +375,8 @@ TEST(ShellTest, SupportsHelloInventoryAndHealth) {
ASSERT_NE(gh_rlht, nullptr);
EXPECT_EQ(gh_rlht->metrics().at("type_id"), "bread.rlht");
EXPECT_EQ(gh_rlht->metrics().at("inventory"), "config_seeded");
EXPECT_TRUE(gh_rlht->has_last_seen());
// Still no device I/O at this point — last_seen stays unset (#87).
EXPECT_FALSE(gh_rlht->has_last_seen());
}

{
Expand All @@ -397,6 +403,31 @@ TEST(ShellTest, SupportsHelloInventoryAndHealth) {
EXPECT_DOUBLE_EQ(response.read_signals().values(0).value().double_value(), 25.0);
}

{
SCOPED_TRACE("get_health_after_read");
// #87: the successful read above is real device contact — last_seen must
// now be set and the io_ok counter must have moved, for rlht0 only.
anolis::deviceprovider::v1::Request get_health;
get_health.set_request_id(7);
get_health.mutable_get_health();
const auto response = session.send(get_health);
ASSERT_EQ(response.status().code(), anolis::deviceprovider::v1::Status::CODE_OK);
const anolis::deviceprovider::v1::DeviceHealth *rlht = nullptr;
const anolis::deviceprovider::v1::DeviceHealth *dcmt = nullptr;
for (const auto &dh : response.get_health().devices()) {
if (dh.device_id() == "rlht0") rlht = &dh;
if (dh.device_id() == "dcmt0") dcmt = &dh;
}
ASSERT_NE(rlht, nullptr);
ASSERT_NE(dcmt, nullptr);
EXPECT_TRUE(rlht->has_last_seen());
EXPECT_NE(rlht->metrics().at("io_ok"), "0");
EXPECT_EQ(rlht->metrics().at("io_failed"), "0");
// dcmt0 has still had no contact.
EXPECT_FALSE(dcmt->has_last_seen());
EXPECT_EQ(dcmt->metrics().at("io_ok"), "0");
}

{
SCOPED_TRACE("call_mock_backend");
// Well-formed call: passes argument validation, then the mock session
Expand Down