New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Speed up page turning on big cre documents #3740

Merged
merged 19 commits into from Mar 12, 2018

Conversation

Projects
None yet
3 participants
@poire-z
Contributor

poire-z commented Mar 11, 2018

Page turning, menu opening, ... everything actually!
They were getting slower as we progress in the book: quite ok at the beginning, really bothering (2-4 seconds) at end of book.

In crengine, at the end of each LVDocView->Render() (and actually, in a lot of places - it has been commented out once in https://github.com/koreader/crengine/pull/31/files#diff-d7ccd90eae9da5e36484d85f57f69246) , there is a call to updateBookMarksRanges().
https://github.com/koreader/crengine/blob/900d56dfc094c2a19a3a9b55a1502ecf36e248ca/crengine/src/lvdocview.cpp#L2523

https://github.com/koreader/crengine/blob/900d56dfc094c2a19a3a9b55a1502ecf36e248ca/crengine/src/lvdocview.cpp#L2956
updateBookMarksRanges() doesn't do much, except calling getCurrentFileHistRecord() , which should return bookmarks for the page, so that crengine can draw them. But in our case, it returns always zero bookmark (so the loop is not run).

https://github.com/koreader/crengine/blob/900d56dfc094c2a19a3a9b55a1502ecf36e248ca/crengine/src/lvdocview.cpp#L3358-L3375
getCurrentFileHistRecord() calls CRFileHist::savePosition() that takes a lot of time, as it manages some internal history and builds a CRBookmark object which seems to take time (dunno why, may be it walks the DOM, more stuff to walk the further we are in the book).
https://github.com/koreader/crengine/blob/900d56dfc094c2a19a3a9b55a1502ecf36e248ca/crengine/src/hist.cpp#L476-L486

We don't need any of that, as we manage our highlights and bookmarks ourselves, and we draw them ourselves over the clean page drawn by crengine.

Just putting crengine.highlight.bookmarks=0 in data/cr3.ini prevents the call to getCurrentFileHistRecord():
https://github.com/koreader/crengine/blob/900d56dfc094c2a19a3a9b55a1502ecf36e248ca/crengine/src/lvdocview.cpp#L2963
(It would be a problem setting it in cr3.ini as we wouldn't know how to update it for those who already have one generated - it is build on first credocument opening after first installation)
But this has a side effect: when opening an already opened book, we stay on page 1 ! Couldn't figure out why.

But it's just as good as doing it simply with a method call, a bit later in the opening process, as this PR does.

On the emulator, the real rendering work takes like 10ms.
Verifying styles hashes and co (to validate the rendering info is still valid) takes 50ms (this could be optimised if we wanted more).
This getCurrentFileHistRecord() was taking 10ms at page 10/5000, 300ms at page 4000/5000.
So, it's a surprisingly huge benefit! Haven't seen any side effect.

Speed up page turning on big cre documents
Page turning, menu opening, ... everything actually
@poire-z

This comment has been minimized.

Contributor

poire-z commented Mar 11, 2018

But unit tests do see side effects... :( dunno why.

poire-z added some commits Mar 11, 2018

@Frenzie

This comment has been minimized.

Member

Frenzie commented Mar 11, 2018

Btw, how did you profile it?

@poire-z

This comment has been minimized.

Contributor

poire-z commented Mar 11, 2018

Just with #define DEBUG_CRENGINE 1 and some added CRLog:info() that prints milliseconds (instead of my old printf) around suspects.

@poire-z

This comment has been minimized.

Contributor

poire-z commented Mar 11, 2018

Can you check (no urge, I'll follow up tomorrow) if first commit is ok (ie: links, go to page, TOC... just work) for you on the emulator? No pb for me on my kobo.
So I know it's just a unit test situation.

poire-z added some commits Mar 11, 2018

@Frenzie

This comment has been minimized.

Member

Frenzie commented Mar 12, 2018

(about the first commit)

When I run the TOC unit test in isolation it passes, but as part of the whole it does not. But it's not the kind of test that should care. Page numbers could be different if a previous test zoomed the document or some such, but the number of TOC elements can't change.

The other tests seem to fail convincingly in isolation.

Using the program I see no obvious issues.

I added this to one of the failing tests:

require "logger".err(readerui.document:getToc())

The results are… there's no difference in the base TOC. The only logical conclusion would be that there's something the matter with readertoc itself. I don't really have time to investigate exactly how it fails atm. The output of require "logger".err(toc) is enormous.

"Good" & "Bad" readerui.document:getToc()

03/12/18-09:42:23 ERROR {
    [1] = {
        ["page"] = 3,
        ["title"] = "Title",
        ["depth"] = 1,
        ["xpointer"] = "/body/DocFragment[2].0"
    },
    [2] = {
        ["page"] = 5,
        ["title"] = "About",
        ["depth"] = 1,
        ["xpointer"] = "/body/DocFragment[3].0"
    },
--etc, it's the same
@poire-z

This comment has been minimized.

Contributor

poire-z commented Mar 12, 2018

Thanks for the tests.
Indeed, not difference, except for the AM in 09:44:48 AM ERROR.
I think there is a problem with any property change that request a re-render. May be on the real program, there are enough other events to generate one before/after, but for unit tests, there may be less of them happening.
Calling GotoPage(1) or onRedrawCurrentView() after setting the property fixes most unit tests (except the toggle portrait mode>landscape>portrait...).
May be I should just add a method to change this property with no additional render.
https://github.com/koreader/crengine/blob/900d56dfc094c2a19a3a9b55a1502ecf36e248ca/crengine/src/lvdocview.cpp#L5924-L5930

@Frenzie

This comment has been minimized.

Member

Frenzie commented Mar 12, 2018

Indeed, not difference, except for the AM in 09:44:48 AM ERROR.

Wait, what? The only thing I changed was my branch. Why would it randomly add AM/PM? :P

@Frenzie

Sounds like a bug in crengine I guess. :-)

@poire-z

This comment has been minimized.

Contributor

poire-z commented Mar 12, 2018

It makes sense crengine-code wise to re-enable this internal history when resizing, as somewhere in the resize workflow, there is a restorePosition() (the counterpart of the CRFileHist::savePosition() we want disabled). Rather do that than hack crengine to remove all this stuff.
Not sure about why there is a need for onRedrawCurrentView(), but these are cheap when internal history is disabled, and we do it once at end of opening, and when changing size, so they doesn't hurt.
And the unit tests are happy with no change needed, so it should be fine.
(I'll test it tonight on my kobo just to be sure it still gives the speedup feeling, before merging if no one opposes)

@frankyifei

This comment has been minimized.

Contributor

frankyifei commented Mar 12, 2018

Is it possible to disable these internal history all together and implement in koreader side?

@poire-z

This comment has been minimized.

Contributor

poire-z commented Mar 12, 2018

We already have it implemented fully on koreader side.

But there is indeed internal support in crengine for bookmarks and history (see https://github.com/koreader/crengine/blob/master/crengine/include/hist.h https://github.com/koreader/crengine/blob/master/crengine/src/hist.cpp). I couldn't figure out where this history records file would be saved to ! I guess they would be used by coolreader UI code, it would fetch the history records as a XML stream and do the saving and feeding back from elsewhere.

But we don't use them at all from koreader - and there are just a few hooks into this in the crengine code we use. This PR just disable the most costly stuff - and my test commits from this morning showed we need to keep a few hooks enabled - the rest shouldn't hurt.
Disabling more would take time and wouldn't give much more benefit I guess (and would increase the delta with other forks).

@Frenzie

This comment has been minimized.

Member

Frenzie commented Mar 12, 2018

@poire-z How's the testing going? :-P

@poire-z

This comment has been minimized.

Contributor

poire-z commented Mar 12, 2018

It's still working fine, so I guess we can merge it.

@Frenzie

This comment has been minimized.

Member

Frenzie commented Mar 12, 2018

@poire-z poire-z merged commit 7d71d73 into koreader:master Mar 12, 2018

1 check passed

ci/circleci Your tests passed on CircleCI!
Details

@poire-z poire-z deleted the poire-z:speedup_cre branch Mar 12, 2018

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment