swift-toolkit: Restoring last read position occasionally fails, opening EPUB to beginning of chapter instead

Overview

Reopening an EPUB trying to restore the last read position seem to work inconsistently, sometimes opening the book to the beginning of the chapter. This bug is currently blocking our transition to R2 which otherwise is complete.

I am unable to reproduce the issue on iOS 14. However I can reproduce it roughly one time out of 5 attempts using the same steps, book, build and device on iOS 13, 12 and 10. (I never tried on 11.) It is easier to reproduce with long books trying to restore a position toward the end of one of the last chapters, but it’s pretty random.

I can’t reproduce this in the r2-testapp but I’ll try to explain what I tried in detail what I am observing.

Build / Test Set-up

• Xcode 11.5 toolchain
• carthage 0.36.0
• R2 version 2.0.0-beta.1
• test devices: iPhone 11 iOS 14.4 / iPhone 6 iOS 12.5.1
• simulators: iPads / iPhones iOS 13.5, 12.4, 10.3.1
• Focusing on epubs without DRM (e.g. Treasure Island, which is also present in the testapp). DRM’ed books exhibit same behavior though.

R2 Set-up

The way R2 is integrated in our app (SimplyE) matches the r2-testapp’s – as a matter of fact I copied its architecture. As far as restoring the reading position is concerned, my understanding is that one simply has to pass the desired Locator to the initialLocation parameter in the EPUBNavigatorViewController initializer. Is this correct or is there more to it?

I also verified the locator i am passing is always the same, with or without experiencing the bug.

Investigation

I’ve tried to follow how the initialLocation locator is propagated at runtime inside the R2 navigator code, to try to understand where it is getting lost. I see that it is passed to the reloadSpreads(at:) function, and there i verified a non-zero initialIndex is always found.

The code then flows to PaginationView::setCurrentIndex(_:location:) and then loadView(at:location:completion:). I verified the guards in those functions are not triggered.

From there control passes to EPUBReflowableSpreadView::go(to:completion:), which may be called multiple times during initialization from many places. I assume this is expected?

This is where things get confusing. When the bug happens the last go(to:completion:) call is for a Locator with progression == 0. This seems to come from a polling timer, for updating the user setting style. In this last function invocation we call go(to:) with the currentLocation value, which is incorrect because its progression is 0. Shouldn’t that still be the initialLocation i passed in in the navigator’s initializer, since the reader is still setting itself up? (There’s a spinner on the screen at this time.) I just can’t figure out where that initialLocation ends up going, or why/if it’s being overwritten.

From another POV, I noticed that on the r2-testapp navigator(_:locationDidChange:) is called twice (once with progression==0, then with the correct locator) but on our app it’s only called once, and when the bug happens the locator.progression is 0. That callback is also called from another polling timer, which makes me think order of execution is not guaranteed to be identical across 2 identical instantiations of the navigator.

I also noticed that if i start putting a lot of breakpoints with debugger output (which slows down execution), the bug is more likely to be triggered. This hints at possible race conditions, but it’s just a conjecture.

Long write-up, sorry… final thoughts

I’ve tried many other approaches (e.g. trying to follow the spreads set-up, or how the Locator progression property is being set) but probably i should stop here since I’m rambling at this point.

Thanks in advance for any help/pointers/suggestions. I realize the fact that the r2-testapp is fine probably means I have a bug in my set-up, but on the other hand this random behavior could mean something is off inside r2-navigator, but I ran out of things to look into.