iOS: Crash in RustLogins/Places forceClose()

[garvankeeley]

x-post mozilla-mobile/firefox-ios#5597

The incidence of this crash has shot up with iOS 13. The background task is being terminated for taking too long, but it looks like it is hung in forceClose().

Reason: Namespace RUNNINGBOARD, Code 0xdead10cc
0   libsystem_kernel.dylib        	0x000000018ada29ec kevent_id + 8
1   libdispatch.dylib             	0x000000018ac38e44 _dispatch_kq_poll + 332 (event_kevent.c:750)
2   libdispatch.dylib             	0x000000018ac397e0 _dispatch_event_loop_wait_for_ownership$VARIANT$mp + 412 (event_kevent.c:2222)
3   libdispatch.dylib             	0x000000018ac28ec4 __DISPATCH_WAIT_FOR_QUEUE__ + 292 (queue.c:1647)
4   libdispatch.dylib             	0x000000018ac28b00 _dispatch_sync_f_slow + 140 (queue.c:1728)
5   Storage                       	0x0000000103283870 RustLogins.forceClose() + 680 (RustLogins.swift:171)
6   Client                        	0x000000010270b008 BrowserProfile._shutdown() + 408 (Profile.swift:343)
7   Client                        	0x00000001026486f4 closure #1 in AppDelegate.syncOnDidEnterBackground(application:) + 344 (AppDelegate.swift:365)
8   Client                        	0x0000000102482b04 thunk for @escaping @callee_guaranteed () -> () + 28 (<compiler-generated>:0)
9   UIKitCore                     	0x000000018efa9ac8 -[_UIBackgroundTaskInfo fireExpirationHandler] + 64 (UIApplication.m:1165)
10  UIKitCore                     	0x000000018efb33ec _fireBackgroundExpirationHandlers + 640 (UIApplication.m:13086)
11  UIKitCore                     	0x000000018efb3098 -[UIApplication workspaceNoteAssertionExpirationImminent:] + 136 (UIApplication.m:3859)

┆Issue is synchronized with this Jira Story
┆Story Points: 3
┆Sprint: SYNC - end 2019-11-08

[garvankeeley]

iOS 13 has new background refresh APIs, but these will still crash if forceClose() is deadlocked.

[garvankeeley]

This PR might help mozilla-mobile/firefox-ios#5692
This allows more time for db files to get unlocked (maybe they take a few ms to fully unlock?) when app is backgrounded.
I'll report back when I have more info.

[st3fan]

I was listening to the Accidental Tech podcast and those folks were ranting that on iOS 13 you get a hard crash in a background task if you still have open file descriptors.

So I wonder if this crash is happening not because forceClose() takes too long, but instead because it still leaves a file descriptor open?

[garvankeeley]

I believe that is the most likely case. On the rust side IIRC they said they can't do any more than they do to close the file. There is a possibility that there are some async operations which haven't completed, if that PR fixes the problem we can use that info to further understand the original problem.

[st3fan]

This bug only happens on iOS 13.0, 13.1 and 13.2. There are no reports for iOS 12.

[st3fan]

From https://developer.apple.com/library/archive/technotes/tn2151/_index.html

The exception code 0xdead10cc indicates that an application has been terminated by the OS because it held on to a file lock or sqlite database lock during suspension. If your application is performing operations on a locked file or sqlite database at suspension time, it must request additional background execution time to complete those operations and relinquish the lock before suspending.

[garvankeeley]

This bug only happens on iOS 13.0, 13.1 and 13.2. There are no reports for iOS 12.

This PR should fix the bug then, if the file was staying locked then iOS 12 would have killed it also.

[st3fan]

@garvankeeley Would you consider your PR for Firefox iOS a workaround or a fix? I am just wondering if the root cause is an issue (or behaviour) in RustLogins code. If that is the case then I think we should still ask for a change there. What do you think?

[thomcc]

I'm genuinely unsure what we can do about it. when you forceClose, we call sqlite3_interrupt, which might not succeed in interrupting the call. Additionally, it does need to take a lock to invoke interrupt, to satisfy the caveat of "it is not safe to call this routine with a database connection that is closed or might close before sqlite3_interrupt() returns", which is precisely the case here.

[garvankeeley]

Workaround. But it could also be a workaround for an sqlcipher bug, that the db takes additional time to release the file lock.

[garvankeeley]

Stefan: you may be interested to know, Apple doesn't allow sqlcipher files to be locked in the Shared dir, but tolerates non-sqlcipher db locks (it checks the file header to see if it is a DB file, and this fails on sqlcipher db). sqlcipher/sqlcipher#255

[st3fan]

Why do we call forceClose() and not simply close() (sqlite_close?) We are not in a hurry to close everyting right? We ask for background time to finish a sync and then shut down the profile, so why do we need to forceClose?

[garvankeeley]

I see the problem, login sync is running on another thread.

[garvankeeley]

Correction: The PR I referenced above ( mozilla-mobile/firefox-ios#5692. ) will not affect this bug

[garvankeeley]

Closing, as we have a workaround for most of the problem (
mozilla-mobile/firefox-ios#5597 (comment)), and the remaining problem is this bug #2100