Richard Newman [:rnewman] Reporter
	Description • 9 years ago

This will block the main thread, and if it takes more than 20 seconds, sadness will ensue.

#0	0x000000010fd8a13b in SQLiteDBConnection.(openWithFlags in _3F4389F18684E136A114953F0C3F855C)(Int32) -> NSError? at /Users/rnewman/moz/git/s2fxios/Storage/ThirdParty/SwiftData.swift:407
#1	0x000000010fd87238 in SQLiteDBConnection.init(filename : String, flags : Int32, key : String?, prevKey : String?) -> SQLiteDBConnection? at /Users/rnewman/moz/git/s2fxios/Storage/ThirdParty/SwiftData.swift:301
#2	0x000000010fd7f760 in SQLiteDBConnection.__allocating_init(filename : String, flags : Int32, key : String?, prevKey : String?) -> SQLiteDBConnection? ()
#3	0x000000010fd9054b in SwiftData.((getSharedConnection in _3F4389F18684E136A114953F0C3F855C)(SwiftData) -> () -> SQLiteDBConnection?).(closure #1) at /Users/rnewman/moz/git/s2fxios/Storage/ThirdParty/SwiftData.swift:80
#4	0x000000010fd7dc87 in thunk ()
#5	0x000000011539b49b in _dispatch_client_callout ()
#6	0x000000011537ffb5 in _dispatch_barrier_sync_f_invoke ()
#7	0x000000010fd7f555 in SwiftData.(getSharedConnection in _3F4389F18684E136A114953F0C3F855C)() -> SQLiteDBConnection? at /Users/rnewman/moz/git/s2fxios/Storage/ThirdParty/SwiftData.swift:83
#8	0x000000010fd7f860 in SwiftData.withConnection(SwiftData.Flags, cb : (db : SQLiteDBConnection) -> NSError?) -> NSError? at /Users/rnewman/moz/git/s2fxios/Storage/ThirdParty/SwiftData.swift:96
#9	0x000000010fd7fe25 in SwiftData.transaction((db : SQLiteDBConnection) -> Bool) -> NSError? at /Users/rnewman/moz/git/s2fxios/Storage/ThirdParty/SwiftData.swift:140
#10	0x000000010fd6744c in BrowserDB.createOrUpdate([Table]...) -> Bool at /Users/rnewman/moz/git/s2fxios/Storage/SQL/BrowserDB.swift:159
#11	0x000000010fd65c7d in BrowserDB.init(filename : String, secretKey : String?, files : FileAccessor) -> BrowserDB at /Users/rnewman/moz/git/s2fxios/Storage/SQL/BrowserDB.swift:51
#12	0x000000010fd65e60 in BrowserDB.__allocating_init(filename : String, secretKey : String?, files : FileAccessor) -> BrowserDB ()
#13	0x000000010f0faafa in BrowserProfile.(db.getter).(closure #1) at /Users/rnewman/moz/git/s2fxios/Providers/Profile.swift:285
#14	0x000000010efc0be7 in thunk ()
#15	0x000000011539b49b in _dispatch_client_callout ()
#16	0x0000000115386e28 in dispatch_once_f ()
#17	0x000000010f0e6c7e in BrowserProfile.db.getter at /Users/rnewman/moz/git/s2fxios/Providers/Profile.swift:287
#18	0x000000010f0ffe76 in BrowserProfile.((places in _A76D479B096E6A9510AC7CA65ECAC689).getter).(closure #1) at /Users/rnewman/moz/git/s2fxios/Providers/Profile.swift:299
#19	0x000000010f0f21fa in BrowserProfile.(places in _A76D479B096E6A9510AC7CA65ECAC689).getter at /Users/rnewman/moz/git/s2fxios/Providers/Profile.swift:300
#20	0x000000010f0e6df3 in BrowserProfile.history.getter at /Users/rnewman/moz/git/s2fxios/Providers/Profile.swift:307
#21	0x000000010f0e4adf in BrowserProfile.init(localName : String, app : UIApplication?) -> BrowserProfile at /Users/rnewman/moz/git/s2fxios/Providers/Profile.swift:210
#22	0x000000010f0e1eb9 in BrowserProfile.__allocating_init(localName : String, app : UIApplication?) -> BrowserProfile ()
#23	0x000000010f078364 in AppDelegate.getProfile(UIApplication) -> Profile at /Users/rnewman/moz/git/s2fxios/Client/Application/AppDelegate.swift:98
#24	0x000000010f0765f6 in AppDelegate.application(UIApplication, willFinishLaunchingWithOptions : [NSObject : AnyObject]?) -> Bool at /Users/rnewman/moz/git/s2fxios/Client/Application/AppDelegate.swift:32

	Richard Newman [:rnewman] Reporter
	Comment 1 • 9 years ago

I think this might be fine -- I don't remember that simply opening the DB can cause a blocking WAL replay.

We could set SQLITE_ENABLE_SQLLOG in our build and see what prints…

	Richard Newman [:rnewman] Reporter
	Comment 2 • 9 years ago

In ordinary circumstances, this call takes a few hundred microseconds to complete. I'm going to see if there are circumstances in which that's not the case -- e.g., if I can trigger a WAL autocheckpoint on open.

	Stephan Leroux [:sleroux]
	Comment 3 • 9 years ago

What's the harm in moving this in the background thread in case? I see that this is all being caused from the lazy loading of the places DB in BrowserProfile. Could we maybe remove the lazy load property and replace it with a deferred call to load the DB?

	Richard Newman [:rnewman] Reporter
	Comment 4 • 9 years ago

Long story.

We open the DB (in the sqlite sense) when initing the SwiftData object. Whether that happens on the main thread or not, if we still need to block to service a delegate method or finish an initializer, we're still screwed.

That is: it's not the DB open that's the problem, it's _any access to data storage_ on the main thread.

The problem isn't that we open the DB in the init inside .db.getter, it's that we init BrowserProfile on the main thread and doing so needs to touch history (in order to invalidate top sites, in this case).

There isn't any difference between a blocking dispatch_once call that returns the BrowserDB and blocking on a Deferred guarded by dispatch_once that resolves to a BrowserDB.

We could consider lazy-opening the DB, but that just punts the pain until a less controlled time.

In this particular trace, we could run top sites invalidation on a background queue. But we didn't invalidate at all before the last 1.2 builds, so I assume this isn't the issue.

On a broader note: some of our lazy vars exist because it's otherwise not possible to express the co-dependencies between members -- e.g., needing prefs to create an object. I don't remember if this is one of them.

	Richard Newman [:rnewman] Reporter
	Comment 5 • 9 years ago

N.B., we dereferencing self.profile.{history,…} in a bunch of places. The best fix for decoupling opening, I think, is to not open the database connection when initializing BrowserDB.

	Richard Newman [:rnewman] Reporter
	Comment 6 • 9 years ago

… and then everything that holds on to a BrowserDB needs to be aware that it can't, for example, initialize synchronously.

	Richard Newman [:rnewman] Reporter
	Comment 7 • 9 years ago

I wrote up some of those thoughts in Bug 1223105.

I fixed the AppDelegate-blocking DB touch in Bug 1223099.

Beyond that, let's measure.