Merge branch 'mkirk/debug-disappearing'

Signal/src/ViewControllers/DebugUI/DebugUIMessages.m

@@ -27,6 +27,12 @@
 
 NS_ASSUME_NONNULL_BEGIN
 
+@interface TSIncomingMessage (DebugUI)
+
+@property (nonatomic, getter=wasRead) BOOL read;
+
+@end
+
 @interface TSOutgoingMessage (PostDatingDebug)
 
 - (void)setReceivedAtTimestamp:(uint64_t)value;
@@ -232,6 +238,10 @@ NS_ASSUME_NONNULL_BEGIN
                               @"%@ Failed to send Request Group Info message with error: %@", self.logTag, error);
                       }];
               }],
+        [OWSTableItem itemWithTitle:@"Message with stalled timer"
+                        actionBlock:^{
+                            [DebugUIMessages createDisappearingMessagesWhichFailedToStartInThread:thread];
+                        }],
         [OWSTableItem itemWithTitle:@"Inject 10 fake incoming messages"
                         actionBlock:^{
                             [DebugUIMessages injectFakeIncomingMessages:10 thread:thread];
@@ -4155,6 +4165,24 @@ typedef OWSContact * (^OWSContactBlock)(void);
     }];
 }
 
++ (void)createDisappearingMessagesWhichFailedToStartInThread:(TSThread *)thread
+{
+    uint64_t now = [NSDate ows_millisecondTimeStamp];
+    TSIncomingMessage *message = [[TSIncomingMessage alloc]
+        initIncomingMessageWithTimestamp:now
+                                inThread:thread
+                                authorId:thread.recipientIdentifiers.firstObject
+                          sourceDeviceId:0
+                             messageBody:[NSString stringWithFormat:@"Should disappear 60s after %tu", now]
+                           attachmentIds:[NSMutableArray new]
+                        expiresInSeconds:60
+                           quotedMessage:nil
+                            contactShare:nil];
+    // private setter to avoid starting expire machinery.
+    message.read = YES;
+    [message save];
+}
+
 + (void)testIndicScriptsInThread:(TSThread *)thread
 {
     NSArray<NSString *> *strings = @[

SignalServiceKit/src/Messages/Interactions/TSIncomingMessage.m

@@ -118,7 +118,7 @@ NS_ASSUME_NONNULL_BEGIN
     return OWSInteractionType_IncomingMessage;
 }
 
-- (BOOL)shouldStartExpireTimer:(YapDatabaseReadTransaction *)transaction
+- (BOOL)shouldStartExpireTimerWithTransaction:(YapDatabaseReadTransaction *)transaction
 {
     for (NSString *attachmentId in self.attachmentIds) {
         TSAttachment *_Nullable attachment =

SignalServiceKit/src/Messages/Interactions/TSMessage.h

@@ -45,7 +45,7 @@ NS_ASSUME_NONNULL_BEGIN
 - (void)setQuotedMessageThumbnailAttachmentStream:(TSAttachmentStream *)attachmentStream;
 
 - (BOOL)shouldStartExpireTimer;
-- (BOOL)shouldStartExpireTimer:(YapDatabaseReadTransaction *)transaction;
+- (BOOL)shouldStartExpireTimerWithTransaction:(YapDatabaseReadTransaction *)transaction;
 
 #pragma mark - Update With... Methods
 

SignalServiceKit/src/Messages/Interactions/TSMessage.m

@@ -167,12 +167,12 @@ static const NSUInteger OWSMessageSchemaVersion = 4;
 {
     __block BOOL result;
     [self.dbReadConnection readWithBlock:^(YapDatabaseReadTransaction *_Nonnull transaction) {
-        result = [self shouldStartExpireTimer:transaction];
+        result = [self shouldStartExpireTimerWithTransaction:transaction];
     }];
     return result;
 }
 
-- (BOOL)shouldStartExpireTimer:(YapDatabaseReadTransaction *)transaction
+- (BOOL)shouldStartExpireTimerWithTransaction:(YapDatabaseReadTransaction *)transaction
 {
     return self.isExpiringMessage;
 }

SignalServiceKit/src/Messages/Interactions/TSOutgoingMessage.m

@@ -391,7 +391,7 @@ NSString *NSStringForOutgoingMessageRecipientState(OWSOutgoingMessageRecipientSt
     return NO;
 }
 
-- (BOOL)shouldStartExpireTimer:(YapDatabaseReadTransaction *)transaction
+- (BOOL)shouldStartExpireTimerWithTransaction:(YapDatabaseReadTransaction *)transaction
 {
     // It's not clear if we should wait until _all_ recipients have reached "sent or later"
     // (which could never occur if one group member is unregistered) or only wait until

SignalServiceKit/src/Messages/OWSDisappearingMessagesFinder.h

@@ -14,10 +14,14 @@ NS_ASSUME_NONNULL_BEGIN
 
 - (void)enumerateExpiredMessagesWithBlock:(void (^_Nonnull)(TSMessage *message))block
                               transaction:(YapDatabaseReadTransaction *)transaction;
+
 - (void)enumerateUnstartedExpiringMessagesInThread:(TSThread *)thread
                                              block:(void (^_Nonnull)(TSMessage *message))block
                                        transaction:(YapDatabaseReadTransaction *)transaction;
 
+- (void)enumerateMessagesWhichFailedToStartExpiringWithBlock:(void (^_Nonnull)(TSMessage *message))block
+                                                 transaction:(YapDatabaseReadTransaction *)transaction;
+
 /**
  * @return
  *   uint64_t millisecond timestamp wrapped in a number. Retrieve with `unsignedLongLongvalue`.

SignalServiceKit/src/Messages/OWSDisappearingMessagesFinder.m

@@ -5,6 +5,7 @@
 #import "OWSDisappearingMessagesFinder.h"
 #import "NSDate+OWS.h"
 #import "OWSPrimaryStorage.h"
+#import "TSIncomingMessage.h"
 #import "TSMessage.h"
 #import "TSOutgoingMessage.h"
 #import "TSThread.h"
@@ -41,6 +42,44 @@ static NSString *const OWSDisappearingMessageFinderExpiresAtIndex = @"index_mess
     return [messageIds copy];
 }
 
+- (NSArray<NSString *> *)fetchMessageIdsWhichFailedToStartExpiring:(YapDatabaseReadTransaction *_Nonnull)transaction
+{
+    OWSAssert(transaction);
+
+    NSMutableArray<NSString *> *messageIds = [NSMutableArray new];
+    NSString *formattedString =
+        [NSString stringWithFormat:@"WHERE %@ = 0", OWSDisappearingMessageFinderExpiresAtColumn];
+
+    YapDatabaseQuery *query = [YapDatabaseQuery queryWithFormat:formattedString];
+    [[transaction ext:OWSDisappearingMessageFinderExpiresAtIndex]
+        enumerateKeysAndObjectsMatchingQuery:query
+                                  usingBlock:^void(NSString *collection, NSString *key, id object, BOOL *stop) {
+                                      if (![object isKindOfClass:[TSMessage class]]) {
+                                          OWSFail(@"%@ in %s object was unexpected class: %@",
+                                              self.logTag,
+                                              __PRETTY_FUNCTION__,
+                                              object);
+                                          return;
+                                      }
+                                      
+                                      // We'll need to update if we ever support expiring other message types
+                                      OWSAssert([object isKindOfClass:[TSOutgoingMessage class]] || [object isKindOfClass:[TSIncomingMessage class]]);
+                                      
+                                      TSMessage *message = (TSMessage *)object;
+                                      if ([message shouldStartExpireTimerWithTransaction:transaction]) {
+                                          if ([message isKindOfClass:[TSIncomingMessage class]]) {
+                                              TSIncomingMessage *incomingMessage = (TSIncomingMessage *)message;
+                                              if (!incomingMessage.wasRead) {
+                                                  return;
+                                              }
+                                          }
+                                          [messageIds addObject:key];
+                                      }
+                                  }];
+
+    return [messageIds copy];
+}
+
 - (NSArray<NSString *> *)fetchExpiredMessageIdsWithTransaction:(YapDatabaseReadTransaction *_Nonnull)transaction
 {
     OWSAssert(transaction);
@@ -99,11 +138,33 @@ static NSString *const OWSDisappearingMessageFinderExpiresAtIndex = @"index_mess
         if ([message isKindOfClass:[TSMessage class]]) {
             block(message);
         } else {
-            DDLogError(@"%@ unexpected object: %@", self.logTag, message);
+            OWSProdLogAndFail(@"%@ unexpected object: %@", self.logTag, message);
         }
     }
 }
 
+- (void)enumerateMessagesWhichFailedToStartExpiringWithBlock:(void (^_Nonnull)(TSMessage *message))block
+                                                 transaction:(YapDatabaseReadTransaction *)transaction
+{
+    OWSAssert(transaction);
+
+    for (NSString *expiringMessageId in [self fetchMessageIdsWhichFailedToStartExpiring:transaction]) {
+
+        TSMessage *_Nullable message = [TSMessage fetchObjectWithUniqueID:expiringMessageId transaction:transaction];
+        if (![message isKindOfClass:[TSMessage class]]) {
+            OWSProdLogAndFail(@"%@ unexpected object: %@", self.logTag, message);
+            continue;
+        }
+
+        if (![message shouldStartExpireTimerWithTransaction:transaction]) {
+            OWSProdLogAndFail(@"%@ object: %@ shouldn't expire.", self.logTag, message);
+            continue;
+        }
+
+        block(message);
+    }
+}
+
 /**
  * Don't use this in production. Useful for testing.
  * We don't want to instantiate potentially many messages at once.
@@ -177,7 +238,7 @@ static NSString *const OWSDisappearingMessageFinderExpiresAtIndex = @"index_mess
             }
             TSMessage *message = (TSMessage *)object;
 
-            if (![message shouldStartExpireTimer:transaction]) {
+            if (![message shouldStartExpireTimerWithTransaction:transaction]) {
                 return;
             }
 

SignalServiceKit/src/Messages/OWSDisappearingMessagesJob.h

@@ -44,6 +44,8 @@ NS_ASSUME_NONNULL_BEGIN
 // and continue cleaning in the background.
 - (void)startIfNecessary;
 
+- (void)cleanupMessagesWhichFailedToStartExpiringWithTransaction:(YapDatabaseReadWriteTransaction *)transaction;
+
 @end
 
 NS_ASSUME_NONNULL_END

SignalServiceKit/src/Messages/OWSDisappearingMessagesJob.m

@@ -279,6 +279,12 @@ void AssertIsOnDisappearingMessagesQueue()
         self.hasStarted = YES;
 
         dispatch_async(OWSDisappearingMessagesJob.serialQueue, ^{
+            // Theoretically this shouldn't be necessary, but there was a race condition when receiving a backlog
+            // of messages across timer changes which could cause a disappearing message's timer to never be started.
+            [self.databaseConnection readWriteWithBlock:^(YapDatabaseReadWriteTransaction *_Nonnull transaction) {
+                [self cleanupMessagesWhichFailedToStartExpiringWithTransaction:transaction];
+            }];
+
             [self runLoop];
         });
     });
@@ -373,7 +379,7 @@ void AssertIsOnDisappearingMessagesQueue()
         // exception is if we're in close proximity to the disappearanceTimer, in which case a race condition
         // is inevitable.
         if (!recentlyScheduledDisappearanceTimer && deletedCount > 0) {
-            OWSProdLogAndFail(@"%@ unexpectedly deleted disappearing messages via fallback timer.");
+            OWSProdLogAndFail(@"%@ unexpectedly deleted disappearing messages via fallback timer.", self.logTag);
         }
     });
 }
@@ -387,6 +393,18 @@ void AssertIsOnDisappearingMessagesQueue()
     self.nextDisappearanceDate = nil;
 }
 
+#pragma mark - Cleanup
+
+- (void)cleanupMessagesWhichFailedToStartExpiringWithTransaction:(YapDatabaseReadWriteTransaction *)transaction
+{
+    [self.disappearingMessagesFinder enumerateMessagesWhichFailedToStartExpiringWithBlock:^(
+        TSMessage *_Nonnull message) {
+        DDLogWarn(@"%@ starting old timer for message timestamp: %tu", self.logTag, message.timestamp);
+        [self setExpirationForMessage:message expirationStartedAt:message.timestampForSorting transaction:transaction];
+    }
+                                                                              transaction:transaction];
+}
+
 #pragma mark - Notifications
 
 - (void)applicationDidBecomeActive:(NSNotification *)notification