Wordpress-ios: Unresolved Core Data save error

[JavonDavis]

@nheagy it's not happening since v12.6 but I'd still like to bring your attention to this one just incase.

[sentry-io[bot]]

Sentry issue: https://sentry.io/share/issue/d76e584eca16479d8403bb24ec477ea2/

[JavonDavis]

@nheagy This is still happening on 12.8.1 and 12.9 beta, it's not the exact same logs but I think it's related and caused a crash on startup on prod, could you take a look or let me know who might have a better idea of what's up if you haven't worked on this recently? At first I thought it had something to do with the WPSplitViewController but I'm not sure about that anymore and it might just be a Core Data issue.

[designsimply]

Noting that we received a report of the WPiOS (app store version) of the app crashing on startup internally and we think this may be the related crash but are also on the look out for app logs to see if we can find some helpful details in them.

[designsimply]

Moving this to high priority because there are new reports of the app crashing on launch at https://github.com/wordpress-mobile/WordPress-iOS/issues/12338.

[designsimply]

90-day impact: ~9,800 events
Users affected in the last 90 days: 1,100

^{https://sentry.io/share/issue/d76e584eca16479d8403bb24ec477ea2/}

[sentry-io[bot]]

Sentry issue: WORDPRESS-IOS-1AQA

[koke]

There are two different sentry issues for this. Since we save on different methods for main and derived contexts, the backtrace would be different, but they should be grouped together.

[sentry-io[bot]]

Sentry issue: WORDPRESS-IOS-1JW7

[sentry-io[bot]]

Sentry issue: WORDPRESS-IOS-1JX4

[sentry-io[bot]]

Sentry issue: WORDPRESS-IOS-1AY7

[nheagy]

12208 is working! That last one says the entity that failed was Post and has error 1570, which we can lookup and see means that mandatory fields are not filled in. Nice!

[shiki]

@leandroalonso and I have been looking at this for a while now. We, unfortunately, could not find the cause.

What we tried so far

Missing .blog values

Using the nil Post.blog values as clues, we looked at all the code involved with setting .blog values.

We theorized that we are setting Comment.post to something else that is not ReaderPost, has no .blog, and saving it in the DB. Unfortunately, this does not seem to be the case. We're always setting ReaderPost which does not have a blog property at all.

We also could not find a place where we might be setting Post.blog to an invalid object. As an example, we're always using the current Blog when synchronizing posts.

Concurrent Blog Deletion

We wondered whether the dedupe blog feature was causing the Blog values to disappear and causing Posts to be saved without them. This seemed unlikely but we performed an experiment anyway. We modified the code to have this scenario:

1. There are more than 10 duplicate blogs
2. There are local drafts in all the duplicate blogs
3. The dedupe blog is running
4. The blog posts sync (all of the duplicate blogs) are running in another thread

Unfortunately (or fortunately), our code worked well and Core Data recovered without any crashes.

There was an instance where this error was logged:

CoreData: annotation: repairing missing delete propagation for to-one 
relationship blog on object 0x600003958540 (0xc68a1051b9d8ebf7 
<x-coredata://C39DE8F2-B8D8-437A-A2FC-783A13A6EE6F/Post/p402>) 
with bad fault 0x600003661c80 (0xc68a1051bfe4ebd7 
<x-coredata://C39DE8F2-B8D8-437A-A2FC-783A13A6EE6F/Blog/p29>)

There was no crash. And I couldn't reproduce it again.

We included manual interventions while this was happening like:

• Pulling the refresh in the Post List
• Leaving the Blog Details page opened. The Blog Details page was automatically removed after the blog was deleted

State Restoration

We looked at places where we keep Blog inside a UIViewController and its state is restored. It might be that we are setting an old or deleted Blog instance to a Post. This doesn't seem to be the case. For the classes that we found, we are storing the Blog ID when the state is saved and retrieve the Blog from Core Data when the state is restored.

Migration

We tested migrations from WPiOS 12.7 to the recent develop. The 12.7 version uses the WordPress 87 model. No crashes and missing Blogs were observed.

Experiments were done before migrating like:

• Leaving local drafts
• Browsing in Reader so data is filled in

DB Exploration

Using the database from @chaitanyamsv, we found concerning issues.

First, there are 1,752 posts that have nil Blog values.

There are at least 4 duplicates for all of those posts.

The posts with blogs are still there with their duplicates.

What does this mean?

We're not really sure. Our guess is that this is a migration gone wrong. We looked at as far as WordPress 33 and AbstractPost.blog has never been set as _optional_.

In relation to #12338, we tested a migration using this database and we found that the migration fails on WordPress 92 but doesn't crash. Also, something to note is that WordPress 92 was merged on Oct 21st, and was released in production just this week. But the crashes have been happening since June.

Moving Forward

Given that we were not able to reproduce the crashes and we've investigated quite a lot of places, we believe it's now time to gather more information and evaluate preventive measures. We are looking at these options:

• Making sure that ContextManager exceptions are sent to Sentry. Right now, it looks like Sentry is initialized after ContextManager. Sentry might not have a chance to send the errors if a crash happens in Core Data initialization. This might also help with resolving #12338.
• Assuming that Post, Media, and Category objects with nil blogs already exist in the database, we have to look for ways to recover. It could be that we can ignore them and redownload.
• Add more breadcrumbs to Sentry (if that's possible).
• I have not fully proven this yet but it looks like the app will still proceed even if a migration fails. We could probably make some improvements there.

[koke]

Good analysis. There are a couple other things that I found weird but I don't understand enough to investigate:

• We are using NSMergeByPropertyObjectTrumpMergePolicy as the merge policy in our child contexts. I don't fully understand if that can ever lead to a scenario where an entity would be inconsistent, but it still doesn't explain how a post could ever get saved without a blog ID.
• Our child context don't listen for changes on the parent. This is expected, as they were meant to be short-lived and dedicated to a single operation, but I found some that are not like that, like the sharedDerivedContext in NotificationSyncMediator.

[diegoreymendez]

I think this issue may have been affected by something @leandroalonso fixed recently too: https://github.com/wordpress-mobile/WordPress-iOS/pull/13147

Let's keep an eye on this and see if it gets better over the next few days / weeks.

[designsimply]

I don't know why but none of the shareable Sentry links previously noted on this issue are still working. @leandroalonso or @shiki or @diegoreymendez can you show me how to find out if this issue is still being recorded in Sentry?

[leandroalonso]

@designsimply I guess you can find the occurrences here.

You can see that the first issue happens in some of the previous version but has a very low rate in the recent versions.

[leandroalonso]

I guess https://github.com/wordpress-mobile/WordPress-iOS/issues/13429 is related to this issue.

However, this time we were able to reproduce the crash thanks to @rachelmcr. This led me to this part of the code: https://github.com/wordpress-mobile/WordPress-iOS/blob/develop/WordPress/Classes/Services/PostService.m#L282

As the comment mention, if a post is uploaded and deleted in the middle of this process we will call the callback with a nil post. PostCoordinator wasn't prepared to deal with this case, which was causing the crash.

I submitted a PR that should fix this crash (https://github.com/wordpress-mobile/WordPress-iOS/pull/13483). I'm still not sure if we can attribute all the "Unresolved Core Data save error" to that part of the code, but anyway it's a great step on fixing that once and for all.

[leandroalonso]

A few conclusions after working in https://github.com/wordpress-mobile/WordPress-iOS/pull/13483 — which I think solves the same issue described here:

• Basically, we're having this crash due to: Core Data + concurrency
• When you have a revision and multiple calls to upload this same revision are made, the first one to finish will delete the revision. However, this entity is still being used by the other call. This led to this crash.
• Then, somewhere in the code (which I wasn't able to figure out which one it is) we try to save the fresh deleted entity which normally has inconsistent Category (the blog being nil): 💥

Another possible fix might be to make sure our code doesn't make multiple calls to upload the same post, but this would probably be very tricky. So what I did was to delete the revision only in the last request made.

This seems to fix the issue but I'm not 100% sure it will fix all of them. Let's keep an eye on these occurrences on the newest versions.

[designsimply]

Events in the last 90 days: 26,000
Users affected in the last 90 days: 2,300
_{https://sentry.io/organizations/a8c/issues/?project=1438083&query=Unresolved+Core+Data+save+error&statsPeriod=14d}

For the largest case in the list with 17k events affecting 1.4k users, it doesn't look like there's a decrease in the 30d recorded cases even though 14.3 was released 14d ago on 2020-02-24. Maybe it's too soon to tell or maybe the 14.3 target noted on the PR should really be 14.4?

[leandroalonso]

@designsimply 14.3 is still yet to be released, don't? Or am I missing something?

I've performed two small searches to check for "Unresolved Core Data save errors" in 14.3 and 14.3.0.1 and no results yet (but the user base in those versions are very small).

I'd say we're still yet to see the result of #13483. :)

[designsimply]

You're right, I completely mixed up the versions! Sorry about that @leandroalonso. 😞14.2 was released on Feb 24 and 14.3 has now been released as of Mar 9.

Looking again at the search results for Unresolved Core Data save error in Sentry, I'm seeing 345 crashes in 14.3.0.3 (screenshot) since it was released on Mar 9 and 21 crashes so far for 14.4.0.1 (screenshot) since it was released 4d ago on Mar 23.

Do you think we should wait a bit longer then and check 14.4 after it's been out for a few weeks?

[leandroalonso]

@designsimply comparing with some other versions (14.2.0.4 for example) it seems that the number of occurrences have lowered but it still happens a lot. :(

I think we still need to dig some other areas of the code.

[designsimply]

Re-posting a quick summary for tracking purposes… 😇

Sentry Issue: WORDPRESS-IOS-2R4N
Events in 14.3.0.3 since it was released 18d ago on Mar 9: 219
Total events in the last 90 days: 17,000
Users affected in the last 90 days: 1,200
First seen: Nov 4, 2019 10:45:32 PM UTC in 13.4.1.1

All "Unresolved Core Data save error" issues:

• Events in 14.2.0.4 since it was released 32d ago on Feb 24: 428
• Events in 14.3.0.3 since it was released 18d ago on Mar 9: 361

[designsimply]

Events in the last 90d: 19,000
Events in the last 11d: 61 since 14.9 was released on 2020-06-01
Users affected in the last 90d: 419
_{https://sentry.io/share/issue/1dcb161bbb4a4e56b4aabe76dd557b19/}

Last 90d for this issue:

[aerych]

Dug into this one for groundskeeping. Some extra context threaded here: pbMoDN-xo-p2.
Hopefully we'll see some improvement with #14343 #14352 and fewer errors related to TopCommentedPostSTatsRecordValue.postURLString, Category.parentID and Category.blog.
I wasn't able to dig into the issues around Post.blog. I think its likely some of our issues are due to multiple saves across multiple derived contexts happening either in an undefined order, or in a way that allows one context to try to save stale data, and adopting a single (or at least fewer) background contexts would be worth a try.

[designsimply]

Events in the last 90d: 19,000
Users affected in the last 90d: 295
Events in the latest release: 24 (15.3 released 13d ago on 2020-07-24)
_{https://sentry.io/share/issue/1dcb161bbb4a4e56b4aabe76dd557b19/}

Looks like slightly lower overall numbers than before and 39% less (24) in the latest release compared to the last time we checked the latest release (61 in 14.9 12d after it's release).

The overall trend for all "Unresolved Core Data save error" issues has declined dramatically 😍 but the daily numbers such as 84/day are still relatively high compared to other crashes we're tracking.

[designsimply]

Events in the last 90d: 825
Users affected in the last 90d: 280
_{WORDPRESS-IOS-2R4N: https://sentry.io/share/issue/1dcb161bbb4a4e56b4aabe76dd557b19/}

[designsimply]

Events in the last 90d: 715
Users affected in the last 90d: 268
_{WORDPRESS-IOS-2R4N: https://sentry.io/share/issue/1dcb161bbb4a4e56b4aabe76dd557b19/}

[designsimply]

Events in the last 90d: 20,000
Users affected in the last 90d: 243
_{WORDPRESS-IOS-2R4N: https://sentry.io/share/issue/1dcb161bbb4a4e56b4aabe76dd557b19/}

Note: still happening in the latest release but the majority of occurrences are from 15.9 and 16.0.

Whoa 20,000 events is quite a jump 🤔 but it's fewer users affected than last time. @jkmassel can you help me understand what's going on here? Were a bunch of unresolved core data save issues merged into one in Sentry by chance?