Remove `fatalError` in case of persistent store backup failure and add more logging to store migration #2481

jaclync · 2020-06-27T03:54:42Z

Part of #2371

Changes

Since we really see a flood of crashes on Sentry and mentions on App Store reviews, I think removing the fatalError when the app fails to back up the store (removing and copying the pre-existing store) would be a good first step. After checking the crash events from release 4.5, it seems like the crashes weren't only migrating from model version 26 to 27 but also from 27 to 28. Now that we know lots of users couldn't get past the backup step, I think it'd be great to know whether the retry of persistent store loading would work.

This PR removed the fatalError when the app couldn't remove or copy the pre-existing persistent store when it failed to migrate for the first time. The errors that occurred in the backup step are then recorded in the log event where the app either recovers from the retry or not
Added more logging to CoreDataIterativeMigrator on the migration step (including a similar backup step)

It'd still be great to understand why the migration fails in the first place. We'll continue monitoring the logs in the upcoming crash events to know more about the model versions and migration process, and see if the app could recover from the retry.

Testing

I think just CI is sufficient, since we haven't got to reproduce the crash yet. Feel free to manually add a similar logging event, and run in WooCommerce Alpha target with "Release-Alpha" configuration to verify on Sentry. Here's an example of a similar Sentry event that I added.

Update release notes:

I have considered if this change warrants user-facing release notes and have added them to RELEASE-NOTES.txt if necessary.

…st log to Sentry with error level.

peril-woocommerce · 2020-06-27T05:34:35Z

You can trigger an installable build for these changes by visiting CircleCI here.

peril-woocommerce · 2020-06-27T05:34:35Z

You can trigger optional UI/connected tests for these changes by visiting CircleCI here.

peril-woocommerce · 2020-06-27T07:09:43Z

	Warnings
⚠️	PR is missing at least one label.

Generated by 🚫 dangerJS

loremattei · 2020-06-29T12:22:50Z

Hey! I'm moving this to 4.7 because 4.6 has been cut. If you need this to make it to 4.6, please feel free to ping me.

jaclync · 2020-06-29T12:44:54Z

@woocommerce/ios-developers @loremattei I was thinking about trying this for release 4.6, lemme know if you have other thoughts! @shiki I saw that you were also thinking about working on recovery from backup failure, does this align with your plan?

I looked at more crash events on Sentry from release 4.5, and it seems like the crashes were mostly from model version 27 to 28 now (v28 was released in the same release 4.5). So it looks like one of these migration steps failed when migrating from model version 27 to 28:

woocommerce-ios/Storage/Storage/CoreData/CoreDataIterativeMigrator.swift

Lines 201 to 224 in 39e5c78

    
           let tempDestinationURL = createTemporaryFolder(at: url) 
        
           // Migrate from the source model to the target model using the mapping, 
        
           // and store the resulting data at the temporary path. 
        
           let migrator = NSMigrationManager(sourceModel: fromModel, destinationModel: toModel) 
        
           do { 
        
               try migrator.migrateStore(from: url, 
        
                                         sourceType: storeType, 
        
                                         options: nil, 
        
                                         with: mappingModel, 
        
                                         toDestinationURL: tempDestinationURL, 
        
                                         destinationType: storeType, 
        
                                         destinationOptions: nil) 
        
           } catch { 
        
               return false 
        
           } 
        
           do { 
        
               let backupURL = try makeBackup(at: url) 
        
               try copyMigratedOverOriginal(from: tempDestinationURL, to: url) 
        
               try deleteBackupCopies(at: backupURL) 
        
           } catch { 
        
               return false 
        
           }

I added more logging for the error that occurred in this function, and I have a strong suspicion that it might be related to the file system access.

This PR also removed fatalError from the database backup steps, the error(s) are logged later when trying to load the persistent stores again. Feel free to share any concerns!

shiki · 2020-06-29T13:18:02Z

I saw that you were also thinking about working on recovery from backup failure, does this align with your plan?

Yup. You pretty much did it. 😅 I'll still take a look at what else we can do though. Perhaps maybe adding unit tests. Or I could work on #2370.

I'll review this today. Thank you, Jaclyn. 🙇

shiki

✔️ Tested by making the first loadPersistentStores() call fail. The app recovered successfully and app operations still seem to be intact.

shiki · 2020-06-29T14:55:58Z

Storage/Storage/CoreData/CoreDataManager.swift

@@ -48,34 +48,22 @@ public class CoreDataManager: StorageManagerType {

            /// Backup the old Store
            ///
+            var persistentStoreBackupError: Error?


Not related to this line.

Regarding public lazy var persistentContainer: NSPersistentContainer = {. This might be something we can look into in the future. From Apple docs:

If a property marked with the lazy modifier is accessed by multiple threads simultaneously and the property has not yet been initialized, there’s no guarantee that the property will be initialized only once.

🙈

ugh yea I don't feel super good about having persistentContainer: NSPersistentContainer as a public lazy var, since it could be first triggered by anywhere (like the Reviews data source before). maybe this could be part of the effort to untangle Core Data setup from the app setup? #2370

shiki · 2020-06-29T15:17:46Z

Storage/Storage/CoreData/CoreDataIterativeMigrator.swift

@@ -102,7 +102,16 @@ public struct CoreDataIterativeMigrator {
            debugMessages.append(migrationAttemptMessage)
            DDLogWarn(migrationAttemptMessage)

-            guard migrateStore(at: sourceStore, storeType: storeType, fromModel: modelFrom, toModel: modelTo, with: migrateWithModel) == true else {
+            let (success, migrateStoreError) = migrateStore(at: sourceStore,


Not related to this line.

I noticed that the errors we were getting are missing reasons for the failed migrations. For example:

It looks like we don't return any debugging messages for cases where we return false. Example:

woocommerce-ios/Storage/Storage/CoreData/CoreDataIterativeMigrator.swift

Lines 31 to 33 in 4350b45

guard let sourceMetadata = try metadataForPersistentStore(storeType: storeType, at: sourceStore) else {

return (false, [])

}

Do you think we should add messages for those?

Looking more closely, it looks like this will be handled by the do catch.

there are many points of failure in this function CoreDataIterativeMigrator. iterativeMigrate, and I think the most critical one is probably where it migrates the store in this call to migrateStore. later in this file I updated to return the error for each point of failure (actual migration error, or backup error) and adding this error to debugMessages below (L113)

Storage/Storage/CoreData/CoreDataManager.swift

jaclync · 2020-06-30T00:53:45Z

@shiki thanks a lot for the review! I responded to your comments, lemme know if I missed anything. the release branch usually gets merged back to develop within 1-2 days for your testability PR (can ping Platform 9 too) 😄

shiki · 2020-06-30T01:09:18Z

Merge it!

jaclync · 2020-06-30T01:36:20Z

hey @loremattei I just merged this PR to release 4.6 branch! if possible, it'd be great if the changes here in release 4.6 can be merged back to develop for another PR that depends on these. thanks a bunch for wrangling the releases!

Remove fatalError in case of persistent store backup failure and ju…

9d0961e

…st log to Sentry with error level.

jaclync added this to the 4.6 milestone Jun 27, 2020

jaclync requested a review from a team June 27, 2020 03:54

jaclync self-assigned this Jun 27, 2020

jaclync added the [Status] Not Ready for Review label Jun 27, 2020

jaclync removed the request for review from a team June 27, 2020 03:58

Consolidate error logging in retry completion.

d11e21e

Add more logging for store migration.

4350b45

jaclync removed the [Status] Not Ready for Review label Jun 27, 2020

jaclync changed the title ~~Remove fatalError in case of persistent store backup failure~~ Remove fatalError in case of persistent store backup failure and add more logging to store migration Jun 27, 2020

jaclync requested a review from a team June 27, 2020 07:10

loremattei modified the milestones: 4.6 ❄️, 4.7 Jun 29, 2020

jaclync changed the base branch from develop to release/4.6 June 29, 2020 12:45

jaclync modified the milestones: 4.7, 4.6 ❄️ Jun 29, 2020

shiki self-assigned this Jun 29, 2020

shiki approved these changes Jun 29, 2020

View reviewed changes

shiki reviewed Jun 29, 2020

View reviewed changes

Storage/Storage/CoreData/CoreDataManager.swift Show resolved Hide resolved

shiki mentioned this pull request Jun 29, 2020

Improve CoreDataIterativeMigrator Testability #2485

Merged

2 tasks

jaclync merged commit 7807a61 into release/4.6 Jun 30, 2020

jaclync deleted the issue/2371-remove-fatal-error-backing-up-store branch June 30, 2020 01:34

sentry-io bot mentioned this pull request Aug 17, 2020

Find The Cause of Core Data Start-up Crashes #2667

Closed

shiki mentioned this pull request Aug 24, 2020

Crashing at opening for many users #2090

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Remove `fatalError` in case of persistent store backup failure and add more logging to store migration #2481

Remove `fatalError` in case of persistent store backup failure and add more logging to store migration #2481

jaclync commented Jun 27, 2020 •

edited

Loading

peril-woocommerce bot commented Jun 27, 2020 •

edited

Loading

peril-woocommerce bot commented Jun 27, 2020 •

edited

Loading

peril-woocommerce bot commented Jun 27, 2020

loremattei commented Jun 29, 2020

jaclync commented Jun 29, 2020 •

edited

Loading

shiki commented Jun 29, 2020

shiki left a comment

shiki Jun 29, 2020

jaclync Jun 30, 2020

shiki Jun 29, 2020

shiki Jun 29, 2020

jaclync Jun 30, 2020

jaclync commented Jun 30, 2020

shiki commented Jun 30, 2020

jaclync commented Jun 30, 2020

	guard let sourceMetadata = try metadataForPersistentStore(storeType: storeType, at: sourceStore) else {
	return (false, [])
	}

Remove fatalError in case of persistent store backup failure and add more logging to store migration #2481

Remove fatalError in case of persistent store backup failure and add more logging to store migration #2481

Conversation

jaclync commented Jun 27, 2020 • edited Loading

Changes

Testing

peril-woocommerce bot commented Jun 27, 2020 • edited Loading

peril-woocommerce bot commented Jun 27, 2020 • edited Loading

peril-woocommerce bot commented Jun 27, 2020

loremattei commented Jun 29, 2020

jaclync commented Jun 29, 2020 • edited Loading

shiki commented Jun 29, 2020

shiki left a comment

Choose a reason for hiding this comment

shiki Jun 29, 2020

Choose a reason for hiding this comment

jaclync Jun 30, 2020

Choose a reason for hiding this comment

shiki Jun 29, 2020

Choose a reason for hiding this comment

shiki Jun 29, 2020

Choose a reason for hiding this comment

jaclync Jun 30, 2020

Choose a reason for hiding this comment

jaclync commented Jun 30, 2020

shiki commented Jun 30, 2020

jaclync commented Jun 30, 2020

Remove `fatalError` in case of persistent store backup failure and add more logging to store migration #2481

Remove `fatalError` in case of persistent store backup failure and add more logging to store migration #2481

jaclync commented Jun 27, 2020 •

edited

Loading

peril-woocommerce bot commented Jun 27, 2020 •

edited

Loading

peril-woocommerce bot commented Jun 27, 2020 •

edited

Loading

jaclync commented Jun 29, 2020 •

edited

Loading