From f62bf7d18ef479797789daa66fe4356fd09502e5 Mon Sep 17 00:00:00 2001 From: Matthew Chen Date: Thu, 16 Aug 2018 15:15:27 -0400 Subject: [PATCH 1/4] Add logging around 'share from SAE to same conversation' crash. --- .../ConversationViewController.m | 24 ++++++++++++++++++- .../src/Storage/OWSPrimaryStorage.m | 5 ++++ SignalServiceKit/src/Storage/OWSStorage.h | 2 ++ SignalServiceKit/src/Storage/OWSStorage.m | 23 ++++++++++++++++++ 4 files changed, 53 insertions(+), 1 deletion(-) diff --git a/Signal/src/ViewControllers/ConversationView/ConversationViewController.m b/Signal/src/ViewControllers/ConversationView/ConversationViewController.m index f0d3f8bb7..763cdb861 100644 --- a/Signal/src/ViewControllers/ConversationView/ConversationViewController.m +++ b/Signal/src/ViewControllers/ConversationView/ConversationViewController.m @@ -458,6 +458,7 @@ typedef enum : NSUInteger { [[OWSPrimaryStorage sharedManager] updateUIDatabaseConnectionToLatest]; [self createNewMessageMappings]; + DDLogInfo(@"%@ reload view items in configureForThread.", self.logTag); if (![self reloadViewItems]) { OWSFail(@"%@ failed to reload view items in configureForThread.", self.logTag); } @@ -798,6 +799,7 @@ typedef enum : NSUInteger { // Avoid layout corrupt issues and out-of-date message subtitles. self.lastReloadDate = [NSDate new]; self.collapseCutoffDate = [NSDate new]; + DDLogInfo(@"%@ reload view items in resetContentAndLayout.", self.logTag); if (![self reloadViewItems]) { OWSFail(@"%@ failed to reload view items in resetContentAndLayout.", self.logTag); } @@ -3227,7 +3229,10 @@ typedef enum : NSUInteger { OWSAssertIsOnMainThread(); // DDLogVerbose(@"%@ %s", self.logTag, __PRETTY_FUNCTION__); - DDLogInfo(@"%@ uiDatabaseDidUpdateExternally: %zd", self.logTag, self.viewItems.count); + DDLogInfo(@"%@ uiDatabaseDidUpdateExternally: %zd, %d", + self.logTag, + self.viewItems.count, + self.shouldObserveDBModifications); if (self.shouldObserveDBModifications) { // External database modifications can't be converted into incremental updates, @@ -3260,6 +3265,11 @@ typedef enum : NSUInteger { { OWSAssertIsOnMainThread(); + DDLogInfo(@"%@ uiDatabaseDidUpdate, connection snapshot: %llu, mappings snapshot: %llu.", + self.logTag, + self.uiDatabaseConnection.snapshot, + self.messageMappings.snapshotOfLastUpdate); + if (!self.shouldObserveDBModifications) { DDLogInfo(@"%@ uiDatabaseDidUpdate (ignoring): %zd", self.logTag, self.viewItems.count); @@ -3376,6 +3386,7 @@ typedef enum : NSUInteger { } NSUInteger oldViewItemCount = self.viewItems.count; + DDLogInfo(@"%@ reload view items in uiDatabaseDidUpdate.", self.logTag); if (![self reloadViewItems]) { // These errors are rare. OWSFail(@"%@ could not reload view items; hard resetting message mappings.", self.logTag); @@ -4611,6 +4622,12 @@ typedef enum : NSUInteger { return; } + DDLogInfo(@"%@ in %s, %d -> %d", + self.logTag, + __PRETTY_FUNCTION__, + _shouldObserveDBModifications, + shouldObserveDBModifications); + _shouldObserveDBModifications = shouldObserveDBModifications; if (self.shouldObserveDBModifications) { @@ -4880,6 +4897,11 @@ typedef enum : NSUInteger { // Returns NO on error. - (BOOL)reloadViewItems { + DDLogInfo(@"%@ reloadViewItems, connection snapshot: %llu, mappings snapshot: %llu.", + self.logTag, + self.uiDatabaseConnection.snapshot, + self.messageMappings.snapshotOfLastUpdate); + NSMutableArray *viewItems = [NSMutableArray new]; NSMutableDictionary *viewItemCache = [NSMutableDictionary new]; diff --git a/SignalServiceKit/src/Storage/OWSPrimaryStorage.m b/SignalServiceKit/src/Storage/OWSPrimaryStorage.m index 3e8c049b4..30adca844 100644 --- a/SignalServiceKit/src/Storage/OWSPrimaryStorage.m +++ b/SignalServiceKit/src/Storage/OWSPrimaryStorage.m @@ -90,6 +90,9 @@ void VerifyRegistrationsForPrimaryStorage(OWSStorage *storage) // Increase object cache limit. Default is 250. _uiDatabaseConnection.objectCacheLimit = 500; [_uiDatabaseConnection beginLongLivedReadTransaction]; + ((OWSDatabaseConnection *)_uiDatabaseConnection).isReadOnly = YES; + ((OWSDatabaseConnection *)_uiDatabaseConnection).shouldLogLongLived = YES; + [[NSNotificationCenter defaultCenter] addObserver:self selector:@selector(yapDatabaseModified:) name:YapDatabaseModifiedNotification @@ -134,6 +137,8 @@ void VerifyRegistrationsForPrimaryStorage(OWSStorage *storage) { OWSAssertIsOnMainThread(); + DDLogInfo(@"%@ %s", self.logTag, __PRETTY_FUNCTION__); + // Notify observers we're about to update the database connection [[NSNotificationCenter defaultCenter] postNotificationName:OWSUIDatabaseConnectionWillUpdateNotification object:self.dbNotificationObject]; diff --git a/SignalServiceKit/src/Storage/OWSStorage.h b/SignalServiceKit/src/Storage/OWSStorage.h index 94d6f65cd..a19545c69 100644 --- a/SignalServiceKit/src/Storage/OWSStorage.h +++ b/SignalServiceKit/src/Storage/OWSStorage.h @@ -21,6 +21,8 @@ extern NSString *const StorageIsReadyNotification; @interface OWSDatabaseConnection : YapDatabaseConnection @property (atomic, weak) id delegate; +@property (atomic) BOOL isReadOnly; +@property (atomic) BOOL shouldLogLongLived; - (instancetype)init NS_UNAVAILABLE; - (instancetype)initWithDatabase:(YapDatabase *)database diff --git a/SignalServiceKit/src/Storage/OWSStorage.m b/SignalServiceKit/src/Storage/OWSStorage.m index 0795e52b1..65c80f1c5 100644 --- a/SignalServiceKit/src/Storage/OWSStorage.m +++ b/SignalServiceKit/src/Storage/OWSStorage.m @@ -81,6 +81,13 @@ NSString *const kNSUserDefaults_DatabaseExtensionVersionMap = @"kNSUserDefaults_ // Specifically, it causes YDB's "view version" checks to fail. - (void)readWriteWithBlock:(void (^)(YapDatabaseReadWriteTransaction *transaction))block { + if (self.isReadOnly) { + OWSFail(@"%@ write transaction on read-only connection.", self.logTag); + @throw [NSException exceptionWithName:NSGenericException + reason:@"write transaction on read-only connection." + userInfo:nil]; + } + id delegate = self.delegate; OWSAssert(delegate); OWSAssert(delegate.areAllRegistrationsComplete); @@ -112,6 +119,13 @@ NSString *const kNSUserDefaults_DatabaseExtensionVersionMap = @"kNSUserDefaults_ OWSAssert(delegate); OWSAssert(delegate.areAllRegistrationsComplete); + if (self.isReadOnly) { + OWSFail(@"%@ write transaction on read-only connection.", self.logTag); + @throw [NSException exceptionWithName:NSGenericException + reason:@"write transaction on read-only connection." + userInfo:nil]; + } + __block OWSBackgroundTask *_Nullable backgroundTask = nil; if (CurrentAppContext().isMainApp) { backgroundTask = [OWSBackgroundTask backgroundTaskWithLabelStr:__PRETTY_FUNCTION__]; @@ -124,6 +138,15 @@ NSString *const kNSUserDefaults_DatabaseExtensionVersionMap = @"kNSUserDefaults_ }]; } +- (NSArray *)beginLongLivedReadTransaction +{ + if (self.shouldLogLongLived) { + DDLogInfo(@"%@ %s", self.logTag, __PRETTY_FUNCTION__); + } + + return [super beginLongLivedReadTransaction]; +} + @end #pragma mark - From 87d51aaa82e52faae0bd7bd3d9edad547fca49db Mon Sep 17 00:00:00 2001 From: Matthew Chen Date: Thu, 16 Aug 2018 15:15:37 -0400 Subject: [PATCH 2/4] "Bump build to 2.29.0.11." --- Signal/Signal-Info.plist | 2 +- SignalShareExtension/Info.plist | 2 +- 2 files changed, 2 insertions(+), 2 deletions(-) diff --git a/Signal/Signal-Info.plist b/Signal/Signal-Info.plist index 605a70d0b..2f1467c2c 100644 --- a/Signal/Signal-Info.plist +++ b/Signal/Signal-Info.plist @@ -38,7 +38,7 @@ CFBundleVersion - 2.29.0.10 + 2.29.0.11 ITSAppUsesNonExemptEncryption LOGS_EMAIL diff --git a/SignalShareExtension/Info.plist b/SignalShareExtension/Info.plist index d163a3e46..c0bac9d98 100644 --- a/SignalShareExtension/Info.plist +++ b/SignalShareExtension/Info.plist @@ -19,7 +19,7 @@ CFBundleShortVersionString 2.29.0 CFBundleVersion - 2.29.0.10 + 2.29.0.11 ITSAppUsesNonExemptEncryption NSAppTransportSecurity From e3378dec65e14b6b4591b1cb298303c5869b2d10 Mon Sep 17 00:00:00 2001 From: Matthew Chen Date: Thu, 16 Aug 2018 16:08:39 -0400 Subject: [PATCH 3/4] Revert "Add logging around 'share from SAE to same conversation' crash." This reverts commit f62bf7d18ef479797789daa66fe4356fd09502e5. --- .../ConversationViewController.m | 24 +------------------ .../src/Storage/OWSPrimaryStorage.m | 5 ---- SignalServiceKit/src/Storage/OWSStorage.h | 2 -- SignalServiceKit/src/Storage/OWSStorage.m | 23 ------------------ 4 files changed, 1 insertion(+), 53 deletions(-) diff --git a/Signal/src/ViewControllers/ConversationView/ConversationViewController.m b/Signal/src/ViewControllers/ConversationView/ConversationViewController.m index 763cdb861..f0d3f8bb7 100644 --- a/Signal/src/ViewControllers/ConversationView/ConversationViewController.m +++ b/Signal/src/ViewControllers/ConversationView/ConversationViewController.m @@ -458,7 +458,6 @@ typedef enum : NSUInteger { [[OWSPrimaryStorage sharedManager] updateUIDatabaseConnectionToLatest]; [self createNewMessageMappings]; - DDLogInfo(@"%@ reload view items in configureForThread.", self.logTag); if (![self reloadViewItems]) { OWSFail(@"%@ failed to reload view items in configureForThread.", self.logTag); } @@ -799,7 +798,6 @@ typedef enum : NSUInteger { // Avoid layout corrupt issues and out-of-date message subtitles. self.lastReloadDate = [NSDate new]; self.collapseCutoffDate = [NSDate new]; - DDLogInfo(@"%@ reload view items in resetContentAndLayout.", self.logTag); if (![self reloadViewItems]) { OWSFail(@"%@ failed to reload view items in resetContentAndLayout.", self.logTag); } @@ -3229,10 +3227,7 @@ typedef enum : NSUInteger { OWSAssertIsOnMainThread(); // DDLogVerbose(@"%@ %s", self.logTag, __PRETTY_FUNCTION__); - DDLogInfo(@"%@ uiDatabaseDidUpdateExternally: %zd, %d", - self.logTag, - self.viewItems.count, - self.shouldObserveDBModifications); + DDLogInfo(@"%@ uiDatabaseDidUpdateExternally: %zd", self.logTag, self.viewItems.count); if (self.shouldObserveDBModifications) { // External database modifications can't be converted into incremental updates, @@ -3265,11 +3260,6 @@ typedef enum : NSUInteger { { OWSAssertIsOnMainThread(); - DDLogInfo(@"%@ uiDatabaseDidUpdate, connection snapshot: %llu, mappings snapshot: %llu.", - self.logTag, - self.uiDatabaseConnection.snapshot, - self.messageMappings.snapshotOfLastUpdate); - if (!self.shouldObserveDBModifications) { DDLogInfo(@"%@ uiDatabaseDidUpdate (ignoring): %zd", self.logTag, self.viewItems.count); @@ -3386,7 +3376,6 @@ typedef enum : NSUInteger { } NSUInteger oldViewItemCount = self.viewItems.count; - DDLogInfo(@"%@ reload view items in uiDatabaseDidUpdate.", self.logTag); if (![self reloadViewItems]) { // These errors are rare. OWSFail(@"%@ could not reload view items; hard resetting message mappings.", self.logTag); @@ -4622,12 +4611,6 @@ typedef enum : NSUInteger { return; } - DDLogInfo(@"%@ in %s, %d -> %d", - self.logTag, - __PRETTY_FUNCTION__, - _shouldObserveDBModifications, - shouldObserveDBModifications); - _shouldObserveDBModifications = shouldObserveDBModifications; if (self.shouldObserveDBModifications) { @@ -4897,11 +4880,6 @@ typedef enum : NSUInteger { // Returns NO on error. - (BOOL)reloadViewItems { - DDLogInfo(@"%@ reloadViewItems, connection snapshot: %llu, mappings snapshot: %llu.", - self.logTag, - self.uiDatabaseConnection.snapshot, - self.messageMappings.snapshotOfLastUpdate); - NSMutableArray *viewItems = [NSMutableArray new]; NSMutableDictionary *viewItemCache = [NSMutableDictionary new]; diff --git a/SignalServiceKit/src/Storage/OWSPrimaryStorage.m b/SignalServiceKit/src/Storage/OWSPrimaryStorage.m index 30adca844..3e8c049b4 100644 --- a/SignalServiceKit/src/Storage/OWSPrimaryStorage.m +++ b/SignalServiceKit/src/Storage/OWSPrimaryStorage.m @@ -90,9 +90,6 @@ void VerifyRegistrationsForPrimaryStorage(OWSStorage *storage) // Increase object cache limit. Default is 250. _uiDatabaseConnection.objectCacheLimit = 500; [_uiDatabaseConnection beginLongLivedReadTransaction]; - ((OWSDatabaseConnection *)_uiDatabaseConnection).isReadOnly = YES; - ((OWSDatabaseConnection *)_uiDatabaseConnection).shouldLogLongLived = YES; - [[NSNotificationCenter defaultCenter] addObserver:self selector:@selector(yapDatabaseModified:) name:YapDatabaseModifiedNotification @@ -137,8 +134,6 @@ void VerifyRegistrationsForPrimaryStorage(OWSStorage *storage) { OWSAssertIsOnMainThread(); - DDLogInfo(@"%@ %s", self.logTag, __PRETTY_FUNCTION__); - // Notify observers we're about to update the database connection [[NSNotificationCenter defaultCenter] postNotificationName:OWSUIDatabaseConnectionWillUpdateNotification object:self.dbNotificationObject]; diff --git a/SignalServiceKit/src/Storage/OWSStorage.h b/SignalServiceKit/src/Storage/OWSStorage.h index a19545c69..94d6f65cd 100644 --- a/SignalServiceKit/src/Storage/OWSStorage.h +++ b/SignalServiceKit/src/Storage/OWSStorage.h @@ -21,8 +21,6 @@ extern NSString *const StorageIsReadyNotification; @interface OWSDatabaseConnection : YapDatabaseConnection @property (atomic, weak) id delegate; -@property (atomic) BOOL isReadOnly; -@property (atomic) BOOL shouldLogLongLived; - (instancetype)init NS_UNAVAILABLE; - (instancetype)initWithDatabase:(YapDatabase *)database diff --git a/SignalServiceKit/src/Storage/OWSStorage.m b/SignalServiceKit/src/Storage/OWSStorage.m index 65c80f1c5..0795e52b1 100644 --- a/SignalServiceKit/src/Storage/OWSStorage.m +++ b/SignalServiceKit/src/Storage/OWSStorage.m @@ -81,13 +81,6 @@ NSString *const kNSUserDefaults_DatabaseExtensionVersionMap = @"kNSUserDefaults_ // Specifically, it causes YDB's "view version" checks to fail. - (void)readWriteWithBlock:(void (^)(YapDatabaseReadWriteTransaction *transaction))block { - if (self.isReadOnly) { - OWSFail(@"%@ write transaction on read-only connection.", self.logTag); - @throw [NSException exceptionWithName:NSGenericException - reason:@"write transaction on read-only connection." - userInfo:nil]; - } - id delegate = self.delegate; OWSAssert(delegate); OWSAssert(delegate.areAllRegistrationsComplete); @@ -119,13 +112,6 @@ NSString *const kNSUserDefaults_DatabaseExtensionVersionMap = @"kNSUserDefaults_ OWSAssert(delegate); OWSAssert(delegate.areAllRegistrationsComplete); - if (self.isReadOnly) { - OWSFail(@"%@ write transaction on read-only connection.", self.logTag); - @throw [NSException exceptionWithName:NSGenericException - reason:@"write transaction on read-only connection." - userInfo:nil]; - } - __block OWSBackgroundTask *_Nullable backgroundTask = nil; if (CurrentAppContext().isMainApp) { backgroundTask = [OWSBackgroundTask backgroundTaskWithLabelStr:__PRETTY_FUNCTION__]; @@ -138,15 +124,6 @@ NSString *const kNSUserDefaults_DatabaseExtensionVersionMap = @"kNSUserDefaults_ }]; } -- (NSArray *)beginLongLivedReadTransaction -{ - if (self.shouldLogLongLived) { - DDLogInfo(@"%@ %s", self.logTag, __PRETTY_FUNCTION__); - } - - return [super beginLongLivedReadTransaction]; -} - @end #pragma mark - From f89fa8359b374ee8d637523716a7b62e0133b1fb Mon Sep 17 00:00:00 2001 From: Matthew Chen Date: Thu, 16 Aug 2018 16:09:00 -0400 Subject: [PATCH 4/4] Revert "Add logging around 'SAE to same thread' crash." This reverts commit eee2f7c8c6098adddb35f63e0b231322dec8f842. --- .../ConversationViewController.m | 30 ++++++------------- 1 file changed, 9 insertions(+), 21 deletions(-) diff --git a/Signal/src/ViewControllers/ConversationView/ConversationViewController.m b/Signal/src/ViewControllers/ConversationView/ConversationViewController.m index f0d3f8bb7..18e387b51 100644 --- a/Signal/src/ViewControllers/ConversationView/ConversationViewController.m +++ b/Signal/src/ViewControllers/ConversationView/ConversationViewController.m @@ -3226,8 +3226,7 @@ typedef enum : NSUInteger { { OWSAssertIsOnMainThread(); - // DDLogVerbose(@"%@ %s", self.logTag, __PRETTY_FUNCTION__); - DDLogInfo(@"%@ uiDatabaseDidUpdateExternally: %zd", self.logTag, self.viewItems.count); + DDLogVerbose(@"%@ %s", self.logTag, __PRETTY_FUNCTION__); if (self.shouldObserveDBModifications) { // External database modifications can't be converted into incremental updates, @@ -3242,8 +3241,6 @@ typedef enum : NSUInteger { - (void)uiDatabaseWillUpdate:(NSNotification *)notification { - DDLogInfo(@"%@ uiDatabaseWillUpdate: %zd", self.logTag, self.viewItems.count); - // HACK to work around radar #28167779 // "UICollectionView performBatchUpdates can trigger a crash if the collection view is flagged for layout" // more: https://github.com/PSPDFKit-labs/radar.apple.com/tree/master/28167779%20-%20CollectionViewBatchingIssue @@ -3261,13 +3258,10 @@ typedef enum : NSUInteger { OWSAssertIsOnMainThread(); if (!self.shouldObserveDBModifications) { - DDLogInfo(@"%@ uiDatabaseDidUpdate (ignoring): %zd", self.logTag, self.viewItems.count); - return; } - - DDLogInfo(@"%@ uiDatabaseDidUpdate (ignoring): %zd", self.logTag, self.viewItems.count); - // DDLogVerbose(@"%@ %s", self.logTag, __PRETTY_FUNCTION__); + + DDLogVerbose(@"%@ %s", self.logTag, __PRETTY_FUNCTION__); NSArray *notifications = notification.userInfo[OWSUIDatabaseConnectionNotificationsKey]; OWSAssert([notifications isKindOfClass:[NSArray class]]); @@ -3400,8 +3394,7 @@ typedef enum : NSUInteger { for (YapDatabaseViewRowChange *rowChange in rowChanges) { switch (rowChange.type) { case YapDatabaseViewChangeDelete: { - DDLogInfo(@"%@ YapDatabaseViewChangeDelete collectionKey: %@, indexPath: %@, finalIndex: %lu", - self.logTag, + DDLogVerbose(@"YapDatabaseViewChangeDelete collectionKey: %@, indexPath: %@, finalIndex: %lu", rowChange.collectionKey, rowChange.indexPath, (unsigned long)rowChange.finalIndex); @@ -3411,8 +3404,7 @@ typedef enum : NSUInteger { break; } case YapDatabaseViewChangeInsert: { - DDLogInfo(@"%@ YapDatabaseViewChangeInsert collectionKey: %@, newIndexPath: %@, finalIndex: %lu", - self.logTag, + DDLogVerbose(@"YapDatabaseViewChangeInsert collectionKey: %@, newIndexPath: %@, finalIndex: %lu", rowChange.collectionKey, rowChange.newIndexPath, (unsigned long)rowChange.finalIndex); @@ -3429,9 +3421,8 @@ typedef enum : NSUInteger { break; } case YapDatabaseViewChangeMove: { - DDLogInfo(@"%@ YapDatabaseViewChangeMove collectionKey: %@, indexPath: %@, newIndexPath: %@, " - @"finalIndex: %lu", - self.logTag, + DDLogVerbose(@"YapDatabaseViewChangeMove collectionKey: %@, indexPath: %@, newIndexPath: %@, " + @"finalIndex: %lu", rowChange.collectionKey, rowChange.indexPath, rowChange.newIndexPath, @@ -3440,8 +3431,7 @@ typedef enum : NSUInteger { break; } case YapDatabaseViewChangeUpdate: { - DDLogInfo(@"%@ YapDatabaseViewChangeUpdate collectionKey: %@, indexPath: %@, finalIndex: %lu", - self.logTag, + DDLogVerbose(@"YapDatabaseViewChangeUpdate collectionKey: %@, indexPath: %@, finalIndex: %lu", rowChange.collectionKey, rowChange.indexPath, (unsigned long)rowChange.finalIndex); @@ -3452,7 +3442,7 @@ typedef enum : NSUInteger { } }; - DDLogInfo(@"%@ self.viewItems.count: %zd -> %zd", self.logTag, oldViewItemCount, self.viewItems.count); + DDLogVerbose(@"self.viewItems.count: %zd -> %zd", oldViewItemCount, self.viewItems.count); BOOL shouldAnimateUpdates = [self shouldAnimateRowUpdates:rowChanges oldViewItemCount:oldViewItemCount]; void (^batchUpdatesCompletion)(BOOL) = ^(BOOL finished) { @@ -5202,8 +5192,6 @@ typedef enum : NSUInteger { - (NSInteger)collectionView:(UICollectionView *)collectionView numberOfItemsInSection:(NSInteger)section { - DDLogInfo(@"%@ collectionView:numberOfItemsInSection: %zd", self.logTag, self.viewItems.count); - return (NSInteger)self.viewItems.count; }