[Darwin] MTRDevice event report should include information about whet…

…her it's received during priming report, as those are likely to be in the far past or not realtime
jtung-apple · Nov 29, 2023 · f6a6451 · f6a6451
1 parent b379158
commit f6a6451
Show file tree

Hide file tree

Showing 4 changed files with 88 additions and 14 deletions.
diff --git a/src/darwin/Framework/CHIP/MTRBaseDevice.h b/src/darwin/Framework/CHIP/MTRBaseDevice.h
@@ -52,6 +52,9 @@ NS_ASSUME_NONNULL_BEGIN
  *                                          Only present when MTREventTimeTypeKey is MTREventTimeTypeSystemUpTime.
  *                MTREventTimestampDateKey : NSDate object.
  *                                           Only present when MTREventTimeTypeKey is MTREventTimeTypeTimestampDate.
+ *                MTREventIsHistoricalKey : NSNumber-wrapped BOOL value.
+ *                                          Value is YES if the event is in the far past or not realtime.
+ *                                          Only present when MTREventPathKey is present.
  *
  *                Only one of MTREventTimestampDateKey and MTREventSystemUpTimeKey will be present, depending on the value for
  *                MTREventTimeTypeKey.
@@ -141,6 +144,7 @@ extern NSString * const MTREventPriorityKey MTR_AVAILABLE(ios(16.5), macos(13.4)
 extern NSString * const MTREventTimeTypeKey MTR_AVAILABLE(ios(16.5), macos(13.4), watchos(9.5), tvos(16.5));
 extern NSString * const MTREventSystemUpTimeKey MTR_AVAILABLE(ios(16.5), macos(13.4), watchos(9.5), tvos(16.5));
 extern NSString * const MTREventTimestampDateKey MTR_AVAILABLE(ios(16.5), macos(13.4), watchos(9.5), tvos(16.5));
+extern NSString * const MTREventIsHistoricalKey MTR_NEWLY_AVAILABLE;
 
 @class MTRClusterStateCacheContainer;
 @class MTRAttributeCacheContainer;

diff --git a/src/darwin/Framework/CHIP/MTRBaseDevice.mm b/src/darwin/Framework/CHIP/MTRBaseDevice.mm
@@ -86,6 +86,7 @@
 NSString * const MTREventTimeTypeKey = @"eventTimeType";
 NSString * const MTREventSystemUpTimeKey = @"eventSystemUpTime";
 NSString * const MTREventTimestampDateKey = @"eventTimestampDate";
+NSString * const MTREventIsHistoricalKey = @"eventIsHistorical";
 
 class MTRDataValueDictionaryCallbackBridge;
 
@@ -331,7 +332,7 @@ - (void)invalidateCASESession
         ErrorCallback errorCallback, MTRDeviceResubscriptionScheduledHandler _Nullable resubscriptionScheduledHandler,
         MTRSubscriptionEstablishedHandler _Nullable subscriptionEstablishedHandler, OnDoneHandler _Nullable onDoneHandler)
         : MTRBaseSubscriptionCallback(attributeReportCallback, eventReportCallback, errorCallback, resubscriptionScheduledHandler,
-            subscriptionEstablishedHandler, onDoneHandler)
+              subscriptionEstablishedHandler, onDoneHandler)
     {
     }
 

diff --git a/src/darwin/Framework/CHIP/MTRDevice.mm b/src/darwin/Framework/CHIP/MTRDevice.mm
@@ -106,8 +106,8 @@ - (id)strongObject
         UnsolicitedMessageFromPublisherHandler unsolicitedMessageFromPublisherHandler, ReportBeginHandler reportBeginHandler,
         ReportEndHandler reportEndHandler)
         : MTRBaseSubscriptionCallback(attributeReportCallback, eventReportCallback, errorCallback, resubscriptionCallback,
-            subscriptionEstablishedHandler, onDoneHandler, unsolicitedMessageFromPublisherHandler, reportBeginHandler,
-            reportEndHandler)
+              subscriptionEstablishedHandler, onDoneHandler, unsolicitedMessageFromPublisherHandler, reportBeginHandler,
+              reportEndHandler)
     {
     }
 
@@ -144,7 +144,16 @@ @interface MTRDevice ()
 @property (nonatomic) chip::FabricIndex fabricIndex;
 @property (nonatomic) MTRWeakReference<id<MTRDeviceDelegate>> * weakDelegate;
 @property (nonatomic) dispatch_queue_t delegateQueue;
-@property (nonatomic) NSArray<NSDictionary<NSString *, id> *> * unreportedEvents;
+@property (nonatomic) NSMutableArray<NSDictionary<NSString *, id> *> * unreportedEvents;
+@property (nonatomic) BOOL receivingReport;
+@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):
+//   Unsubscribed (not attemping)
+//   Attempting subscription
+//   Subscribed (gotten subscription response / in steady state with no OnError/OnDone)
+//   Actively receiving report
+//   Actively receiving priming report
 
 /**
  * If subscriptionActive is true that means that either we are in the middle of
@@ -453,13 +462,21 @@ - (void)_handleUnsolicitedMessageFromPublisher
 - (void)_handleReportBegin
 {
     os_unfair_lock_lock(&self->_lock);
-    [self _changeState:MTRDeviceStateReachable];
+    _receivingReport = YES;
+    if (_state != MTRDeviceStateReachable) {
+        _receivingPrimingReport = YES;
+        [self _changeState:MTRDeviceStateReachable];
+    } else {
+        _receivingPrimingReport = NO;
+    }
     os_unfair_lock_unlock(&self->_lock);
 }
 
 - (void)_handleReportEnd
 {
     os_unfair_lock_lock(&self->_lock);
+    _receivingReport = NO;
+    _receivingPrimingReport = NO;
     _estimatedStartTimeFromGeneralDiagnosticsUpTime = nil;
 // For unit testing only
 #ifdef DEBUG
@@ -499,11 +516,27 @@ - (void)_handleAttributeReport:(NSArray<NSDictionary<NSString *, id> *> *)attrib
     os_unfair_lock_unlock(&self->_lock);
 }
 
+#ifdef DEBUG
+- (void)unitTestInjectEventReport:(NSArray<NSDictionary<NSString *, id> *> *)eventReport
+{
+    dispatch_async(self.queue, ^{
+        [self _handleEventReport:eventReport];
+    });
+}
+#endif
+
 - (void)_handleEventReport:(NSArray<NSDictionary<NSString *, id> *> *)eventReport
 {
     os_unfair_lock_lock(&self->_lock);
 
     NSDate * oldEstimatedStartTime = _estimatedStartTime;
+    // Combine with previous unreported events, if they exist
+    NSMutableArray * reportToReturn;
+    if (_unreportedEvents) {
+        reportToReturn = _unreportedEvents;
+    } else {
+        reportToReturn = [NSMutableArray array];
+    }
     for (NSDictionary<NSString *, id> * eventDict in eventReport) {
         // Whenever a StartUp event is received, reset the estimated start time
         //   New subscription case
@@ -564,25 +597,29 @@ - (void)_handleEventReport:(NSArray<NSDictionary<NSString *, id> *> *)eventRepor
                 _estimatedStartTime = potentialSystemStartTime;
             }
         }
+
+        NSMutableDictionary * eventToReturn = eventDict.mutableCopy;
+        if (_receivingPrimingReport) {
+            eventToReturn[MTREventIsHistoricalKey] = @(YES);
+        } else {
+            eventToReturn[MTREventIsHistoricalKey] = @(NO);
+        }
+
+        [reportToReturn addObject:eventToReturn];
     }
     if (oldEstimatedStartTime != _estimatedStartTime) {
         MTR_LOG_DEFAULT("%@ updated estimated start time to %@", self, _estimatedStartTime);
     }
 
-    // Combine with previous unreported events, if they exist
-    if (_unreportedEvents) {
-        eventReport = [_unreportedEvents arrayByAddingObjectsFromArray:eventReport];
-        _unreportedEvents = nil;
-    }
-
     id<MTRDeviceDelegate> delegate = _weakDelegate.strongObject;
     if (delegate) {
+        _unreportedEvents = nil;
         dispatch_async(_delegateQueue, ^{
-            [delegate device:self receivedEventReport:eventReport];
+            [delegate device:self receivedEventReport:reportToReturn];
         });
     } else {
         // save unreported events
-        _unreportedEvents = eventReport;
+        _unreportedEvents = reportToReturn;
     }
 
     os_unfair_lock_unlock(&self->_lock);
@@ -1450,6 +1487,11 @@ - (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;
 

diff --git a/src/darwin/Framework/CHIPTests/MTRDeviceTests.m b/src/darwin/Framework/CHIPTests/MTRDeviceTests.m
@@ -80,6 +80,10 @@ - (void)failSubscribers:(dispatch_queue_t)queue completion:(void (^)(void))compl
 // Test function for whitebox testing
 + (id)CHIPEncodeAndDecodeNSObject:(id)object;
 @end
+
+@interface MTRDevice (Test)
+- (void)unitTestInjectEventReport:(NSArray<NSDictionary<NSString *, id> *> *)eventReport;
+@end
 #endif
 
 @interface MTRDeviceTestDeviceControllerDelegate : NSObject <MTRDeviceControllerDelegate>
@@ -1458,6 +1462,9 @@ - (void)test017_TestMTRDeviceBasics
     // can satisfy the test below.
     XCTestExpectation * gotReportsExpectation = [self expectationWithDescription:@"Attribute and Event reports have been received"];
     __block unsigned eventReportsReceived = 0;
+    __block BOOL reportEnded = NO;
+    __block BOOL gotOneNonPrimingEvent = NO;
+    XCTestExpectation * gotNonPrimingEventExpectation = [self expectationWithDescription:@"Received event outside of priming report"];
     delegate.onEventDataReceived = ^(NSArray<NSDictionary<NSString *, id> *> * eventReport) {
         eventReportsReceived += eventReport.count;
 
@@ -1472,10 +1479,30 @@ - (void)test017_TestMTRDeviceBasics
             } else if (eventTimeType == MTREventTimeTypeTimestampDate) {
                 XCTAssertNotNil(eventDict[MTREventTimestampDateKey]);
             }
+
+            if (!reportEnded) {
+                NSNumber * reportIsHistorical = eventDict[MTREventIsHistoricalKey];
+                XCTAssertTrue(reportIsHistorical.boolValue);
+            } else {
+                if (!gotOneNonPrimingEvent) {
+                    NSNumber * reportIsHistorical = eventDict[MTREventIsHistoricalKey];
+                    XCTAssertFalse(reportIsHistorical.boolValue);
+                    gotOneNonPrimingEvent = YES;
+                    [gotNonPrimingEventExpectation fulfill];
+                }
+            }
         }
     };
     delegate.onReportEnd = ^() {
+        reportEnded = YES;
         [gotReportsExpectation fulfill];
+#ifdef DEBUG
+        [device unitTestInjectEventReport:@[ @{
+            MTREventPathKey : [MTREventPath eventPathWithEndpointID:@(1) clusterID:@(1) eventID:@(1)],
+            MTREventTimeTypeKey : @(MTREventTimeTypeTimestampDate),
+            MTREventTimestampDateKey : [NSDate date]
+        } ]];
+#endif
     };
 
     [device setDelegate:delegate queue:queue];
@@ -1506,7 +1533,7 @@ - (void)test017_TestMTRDeviceBasics
     [device readAttributeWithEndpointID:@(1) clusterID:@(MTRClusterIDTypeLevelControlID) attributeID:@(4) params:nil];
     [device readAttributeWithEndpointID:@(1) clusterID:@(MTRClusterIDTypeLevelControlID) attributeID:@(4) params:nil];
 
-    [self waitForExpectations:@[ subscriptionExpectation, gotReportsExpectation ] timeout:60];
+    [self waitForExpectations:@[ subscriptionExpectation, gotReportsExpectation, gotNonPrimingEventExpectation ] timeout:60];
 
     delegate.onReportEnd = nil;