Skip to content

Commit

Permalink
Improve detection of "historical" events in Matter.framework. (#36506)
Browse files Browse the repository at this point in the history 
We were marking events as "historical" if there were any attributes in the same
report that have the C quality. This had a few problems:

* Some devices randomly report C-quality attributes, for various reasons.
* Some attributes stop having the C quality in favor of Q, in some cases, so
  this is not very forward-compatible.

The fix is to remove this C-quality check altogether.  At that point we have the
following situations:

1. We're setting up a new subscription and getting our initial priming report.
   This case will still have _receivingPrimingReport set, and will cause any
   events reported as part of priming to be marked "historical".
2. We are getting a "priming" report from a server-side subscription resumption
   after the server timed out on a subscription.  If this happens before the
   max-interval elapses, we will see this as a normal report on our
   subscription, but with all attributes and events the server knows about
   included.  In this case, we mark ourselves as being in a "priming report" if
   we get an event that has an event number we have already seen, so that we
   mark any not-seen-before events in that report as "historical", since we
   don't know how long ago they are from.
3. We are getting a normal incremental report, and will not mark any such events
   as "historical".

Since we are now keeping track of last-received event numbers, we can also use
those for our subscriptions and can filter out any events that have an event
number no greater than our last-observed one.
  • Loading branch information
@bzbarsky-apple
bzbarsky-apple authored Nov 15, 2024
1 parent be06550 commit a6253ab
Show file tree
Hide file tree
Showing 2 changed files with 135 additions and 15 deletions.
76 changes: 63 additions & 13 deletions src/darwin/Framework/CHIP/MTRDevice_Concrete.mm
View file
Original file line number Diff line number Diff line change
Expand Up @@ -219,7 +219,23 @@ @interface MTRDevice_Concrete ()
@property (nonatomic, readonly) os_unfair_lock timeSyncLock;

@property (nonatomic) NSMutableArray<NSDictionary<NSString *, id> *> * unreportedEvents;

// The highest event number we have observed, if there was one at all.
@property (nonatomic, readwrite, nullable) NSNumber * highestObservedEventNumber;

// receivingReport is true if we are receving a subscription report. In
// particular, this will be false if we're just getting an attribute value from
// a read-through.
@property (nonatomic) BOOL receivingReport;

// receivingPrimingReport is true if this subscription report is part of us
// establishing a new subscription to the device. When this is true, it is
// _not_ guaranteed that any particular set of attributes will be reported
// (e.g. everything could be filtered out by our DataVersion filters).
// Conversely, when this is false that tells us nothing about attributes _not_
// being reported: a device could randomly decide to rev all data versions and
// report all attributes at any point in time, for example due to performing
// subscription resumption.
@property (nonatomic) BOOL receivingPrimingReport;

// TODO: instead of all the BOOL properties that are some facet of the state, move to internal state machine that has (at least):
Expand Down Expand Up @@ -390,6 +406,7 @@ - (instancetype)initWithNodeID:(NSNumber *)nodeID controller:(MTRDeviceControlle
}
_clusterDataToPersist = nil;
_persistedClusters = [NSMutableSet set];
_highestObservedEventNumber = nil;

// If there is a data store, make sure we have an observer to monitor system clock changes, so
// NSDate-based write coalescing could be reset and not get into a bad state.
Expand Down Expand Up @@ -1954,19 +1971,24 @@ - (void)_injectEventReport:(NSArray<MTRDeviceResponseValueDictionary> *)eventRep
return;
}

// [_deviceController asyncDispatchToMatterQueue:^{ // TODO: This wasn't used previously, not sure why, so keeping it here for thought, but preserving existing behavior
[self _injectPossiblyInvalidEventReport:eventReport];
}

- (void)_injectPossiblyInvalidEventReport:(NSArray<MTRDeviceResponseValueDictionary> *)eventReport
{
dispatch_async(self.queue, ^{
[self _handleEventReport:eventReport];
});
// } errorHandler: nil];
}

// END DRAGON: This is used by the XPC Server to inject attribute reports

#ifdef DEBUG
- (void)unitTestInjectEventReport:(NSArray<NSDictionary<NSString *, id> *> *)eventReport
{
[self _injectEventReport:eventReport];
// Don't validate incoming event reports for unit tests, because we want to
// allow incoming event reports without an MTREventIsHistoricalKey.
[self _injectPossiblyInvalidEventReport:eventReport];
}

- (void)unitTestInjectAttributeReport:(NSArray<NSDictionary<NSString *, id> *> *)attributeReport fromSubscription:(BOOL)isFromSubscription
Expand Down Expand Up @@ -2102,11 +2124,33 @@ - (void)_handleEventReport:(NSArray<NSDictionary<NSString *, id> *> *)eventRepor
}
}

NSMutableDictionary * eventToReturn = eventDict.mutableCopy;
if (_receivingPrimingReport) {
eventToReturn[MTREventIsHistoricalKey] = @(YES);
auto * eventNumber = MTR_SAFE_CAST(eventDict[MTREventNumberKey], NSNumber);
if (!eventNumber) {
MTR_LOG_ERROR("%@ Event %@ missing event number", self, eventDict);
continue;
}

if (!self.highestObservedEventNumber ||
[self.highestObservedEventNumber compare:eventNumber] == NSOrderedAscending) {
// This is an event we have not seen before.
self.highestObservedEventNumber = eventNumber;
} else {
eventToReturn[MTREventIsHistoricalKey] = @(NO);
// We have seen this event already; just filter it out. But also, we must be getting
// some sort of priming report if we are getting events we have seen before.
if (_receivingReport) {
_receivingPrimingReport = YES;
}
continue;
}

NSMutableDictionary * eventToReturn = eventDict.mutableCopy;
// If MTREventIsHistoricalKey is already present, do not mess with the value.
if (eventToReturn[MTREventIsHistoricalKey] == nil) {
if (_receivingPrimingReport) {
eventToReturn[MTREventIsHistoricalKey] = @(YES);
} else {
eventToReturn[MTREventIsHistoricalKey] = @(NO);
}
}

[reportToReturn addObject:eventToReturn];
Expand Down Expand Up @@ -2558,8 +2602,15 @@ - (void)_setupSubscriptionWithReason:(NSString *)reason
// Set up a cluster state cache. We just want this for the logic it has for
// tracking data versions and event numbers so we minimize the amount of data we
// request on resubscribes, so tell it not to store data.
Optional<EventNumber> highestObservedEventNumber;
{
std::lock_guard lock(self->_lock);
if (self.highestObservedEventNumber) {
highestObservedEventNumber = MakeOptional(self.highestObservedEventNumber.unsignedLongLongValue);
}
}
auto clusterStateCache = std::make_unique<ClusterStateCache>(*callback.get(),
/* highestReceivedEventNumber = */ NullOptional,
highestObservedEventNumber,
/* cacheData = */ false);
auto readClient = std::make_unique<ReadClient>(InteractionModelEngine::GetInstance(), exchangeManager,
clusterStateCache->GetBufferedCallback(), ReadClient::InteractionType::Subscribe);
Expand Down Expand Up @@ -2609,6 +2660,10 @@ - (void)_setupSubscriptionWithReason:(NSString *)reason
attributePath.release();
eventPath.release();

// NOTE: We don't set the event number field in readParams, and just let
// the ReadClient get the min event number information from the cluster
// state cache.

// TODO: Change from local filter list generation to rehydrating ClusterStateCache to take advantage of existing filter list sorting algorithm

// SendAutoResubscribeRequest cleans up the params, even on failure.
Expand Down Expand Up @@ -3587,11 +3642,6 @@ - (NSArray *)_getAttributesToReportWithReportedValues:(NSArray<NSDictionary<NSSt
continue;
}

// Additional signal to help mark events as being received during priming report in the event the device rebooted and we get a subscription resumption priming report without noticing it became unreachable first
if (_receivingReport && AttributeHasChangesOmittedQuality(attributePath)) {
_receivingPrimingReport = YES;
}

// check if value is different than cache, and report if needed
BOOL shouldReportAttribute = NO;

Expand Down
74 changes: 72 additions & 2 deletions src/darwin/Framework/CHIPTests/MTRDeviceTests.m
View file
Original file line number Diff line number Diff line change
Expand Up @@ -1470,6 +1470,7 @@ - (void)test017_TestMTRDeviceBasics
__block unsigned eventReportsReceived = 0;
__block BOOL reportEnded = NO;
__block BOOL gotOneNonPrimingEvent = NO;
__block NSNumber * lastObservedEventNumber = @(0);
XCTestExpectation * gotNonPrimingEventExpectation = [self expectationWithDescription:@"Received event outside of priming report"];
delegate.onEventDataReceived = ^(NSArray<NSDictionary<NSString *, id> *> * eventReport) {
eventReportsReceived += eventReport.count;
Expand All @@ -1489,6 +1490,7 @@ - (void)test017_TestMTRDeviceBasics
if (!reportEnded) {
NSNumber * reportIsHistorical = eventDict[MTREventIsHistoricalKey];
XCTAssertTrue(reportIsHistorical.boolValue);
lastObservedEventNumber = eventDict[MTREventNumberKey];
} else {
if (!gotOneNonPrimingEvent) {
NSNumber * reportIsHistorical = eventDict[MTREventIsHistoricalKey];
Expand All @@ -1509,7 +1511,7 @@ - (void)test017_TestMTRDeviceBasics
MTREventTimestampDateKey : [NSDate date],
MTREventIsHistoricalKey : @(NO),
MTREventPriorityKey : @(MTREventPriorityInfo),
MTREventNumberKey : @(1), // Doesn't matter, in practice
MTREventNumberKey : @(lastObservedEventNumber.unsignedLongLongValue + 1),
MTRDataKey : @ {
MTRTypeKey : MTRStructureValueType,
MTRValueKey : @[],
Expand Down Expand Up @@ -3899,6 +3901,70 @@ - (void)test034_TestMTRDeviceHistoricalEvents

// Must have gotten some events (at least StartUp!)
XCTAssertTrue(eventReportsReceived > 0);

// Now try doing some event injection.
__block uint64_t eventNumber = 0x1000000; // Should't have that many events on the device yet!
__block uint64_t firstNewEventNumber = eventNumber;
__auto_type createEventReport = ^{
return @{
MTREventPathKey : [MTREventPath eventPathWithEndpointID:@(1) clusterID:@(1) eventID:@(1)],
MTREventTimeTypeKey : @(MTREventTimeTypeTimestampDate),
MTREventTimestampDateKey : [NSDate date],
MTREventPriorityKey : @(MTREventPriorityInfo),
MTREventNumberKey : @(eventNumber++),
MTRDataKey : @ {
MTRTypeKey : MTRStructureValueType,
MTRValueKey : @[],
},
};
};

eventReportsReceived = 0;
const int eventReportsToInject = 5;
__block XCTestExpectation * eventReportsFinishedExpectation = [self expectationWithDescription:@"Injecting some new event reports"];
__block int historicalEvents = 0;
__block int eventReportsToExpect = eventReportsToInject;

delegate.onEventDataReceived = ^(NSArray<NSDictionary<NSString *, id> *> * eventReport) {
eventReportsReceived += eventReport.count;
for (NSDictionary<NSString *, id> * eventDict in eventReport) {
NSNumber * reportIsHistorical = eventDict[MTREventIsHistoricalKey];
NSNumber * eventNumber = eventDict[MTREventNumberKey];
XCTAssertEqual(reportIsHistorical.boolValue, eventNumber.unsignedLongLongValue < firstNewEventNumber,
@"eventNumber: %@, firstNewEventNumber: %llu", eventNumber, firstNewEventNumber);
historicalEvents += reportIsHistorical.boolValue;
}

if (eventReportsReceived >= eventReportsToExpect) {
[eventReportsFinishedExpectation fulfill];
}
};

for (int i = 0; i < eventReportsToInject; ++i) {
[device unitTestInjectEventReport:@[ createEventReport() ]];
}

[self waitForExpectations:@[ eventReportsFinishedExpectation ] timeout:kTimeoutInSeconds];
XCTAssertEqual(historicalEvents, 0);

// Now inject some mix of historical and non-historical events. Since this
// includes events with old event numbers, those should get filtered out
// from reporting.
const uint64_t expectedHistoricalEvents = 2;
firstNewEventNumber = eventNumber;
eventNumber -= expectedHistoricalEvents;
eventReportsReceived = 0;
historicalEvents = 0;
// Events with already-observed event numbers do not get reported.
eventReportsToExpect = eventReportsToInject - expectedHistoricalEvents;
eventReportsFinishedExpectation = [self expectationWithDescription:@"Injecting a mix of old and new reports"];

for (int i = 0; i < eventReportsToInject; ++i) {
[device unitTestInjectEventReport:@[ createEventReport() ]];
}

[self waitForExpectations:@[ eventReportsFinishedExpectation ] timeout:kTimeoutInSeconds];
XCTAssertEqual(historicalEvents, 0);
}

- (void)test035_TestMTRDeviceSubscriptionNotEstablishedOverXPC
Expand Down Expand Up @@ -4266,13 +4332,17 @@ - (void)test037_MTRDeviceMultipleDelegatesGetReports

- (NSDictionary<NSString *, id> *)_testEventResponseValueWithEndpointID:(NSNumber *)endpointID clusterID:(NSNumber *)clusterID eventID:(NSNumber *)eventID
{
// Pick a large event number, so that in practice these event reports will
// all have larger event numbers than anything that might have been observed
// before.
static uint64_t eventNumber = 0x100000000llu;
return @{
MTREventPathKey : [MTREventPath eventPathWithEndpointID:endpointID clusterID:clusterID eventID:eventID],
MTREventTimeTypeKey : @(MTREventTimeTypeTimestampDate),
MTREventTimestampDateKey : [NSDate date],
MTREventIsHistoricalKey : @(NO),
MTREventPriorityKey : @(MTREventPriorityInfo),
MTREventNumberKey : @(1), // Doesn't matter, in practice
MTREventNumberKey : @(eventNumber++),
// Empty payload.
MTRDataKey : @ {
MTRTypeKey : MTRStructureValueType,
Expand Down

0 comments on commit a6253ab

Please sign in to comment.