Calibre Companion test for very large libraries

[chaley]

A couple of people are testing a version of CC that has been modified to (I hope) better support very large libraries, for example 10,000 books. This thread is for their feedback.

[Sefiriot]

Installed 3.0.6 beta APK as soon as I got it. Something interesting happened when I used the clean DB function for the first time.

I have 0.99GB free space on the internal app storage, as reported by Android. CC database has 9517 books total in it. Cleaning the database took ~8 minutes: I started at 1614 hours, and finished at 1621 hours, close to 1622 hours.

I took note of CC's vital stats before installing 3.0.6:
CC Data size on 3.0.5:
Storage
Total: 175MB
App: 1.44MB
USB storage app: 4.09MB
Data: 169MB

Installed 3.0.6, checked again to make sure nothing else changed. As expected, nothing changed.

On 3.0.6 before cleaning DB:
Total: 175MB
App: 1.44 MB
USB storage app: 4.09MB
Data: 169 MB

Clean started 1614, ended 1621: Cleaning time ~8 minutes

After cleaning:
Total: 269MB
App: 1.44MB
USB storage app: 4.09MB
Data: 263 MB

What? I noticed that after the cleaning, CC also became sluggish, then unresponsive when I tried to use it to browse my collection-- it did that a few times, before finally stopping. My device also stalled, several background apps reporting they'd stopped. I decided to reboot to see if things made a difference.

After reboot, looking again at CC stats:
Total: 164MB
App: 1.44MB
USB storage app: 4.09 MB
Data: 159MB


It may be that rebooting the device is a good idea after cleaning. Going to try that again before sending any new books over tonight.

[chaley]

Originally Posted by Sefiriot

It may be that rebooting the device is a good idea after cleaning. Going to try that again before sending any new books over tonight.

Another thought: although the documents don't say it is necessary, perhaps we should close and reopen the db after the clean. It is easy to imagine reasons why this is a good idea. I will try it.

You can ensure that the db is closed by quitting CC then using "Force Stop" in Android, Settings, Applications, Calibre Companion. I suspect that this will work as well as a reboot.

[Sefiriot]

Just ran the database cleaner again. This time, strangely, cleaning times were in line with your earlier prediction of around 20 minutes, even though the database size remains unchanged at 159MB!

I started the cleaning around 1726-1727 and it finished at 1742. So around 16 minutes. I'm wondering why the first cleaning, which presumably did get rid of whatever in the database was wrong, took so much less time.

Another thing to report: this time on returning to the normal CC browsing screen with books, it was immediately usable, no sluggishness or failures to respond. Dare I suggest that when cleaning produces changes in the database, you would need to shut it down and reboot the app, but not if otherwise?

[chaley]

Originally Posted by Sefiriot

Another thing to report: this time on returning to the normal CC browsing screen with books, it was immediately usable, no sluggishness or failures to respond. Dare I suggest that when cleaning produces changes in the database, you would need to shut it down and reboot the app, but not if otherwise?

My guess is that if it is required in one situation then it should be done in the other, just to avoid problems. Closing and reopening the DB allows the system to clean up after itself, getting rid of journals and the like. Perhaps in this case there was nothing to clean up. Who knows...

I am going to look at what I need to do to auto-close/open the db. It should be easy given all the other robustness changes I made.

[Dhevi]

I hope you don't mind if I piggyback on your thread Sefiriot, but my question will somewhat tie in with the thread topic.

For Calibre Companion: when downloading files to the default directory it will store the ebook in the default directory, and based on folders by author like calibre does.

Will moving the files into created folders to organize by author name have any impact on CC as the library grows in size stored on the device. Where instead of simply scanning just the default directory, now CC is tasked with scanning the subfolders as well...

[DoctorOhh]

Upon upgrading I noticed a subjective increase in speed between changing groups. It switched from 1-1.5 seconds to 1. But the bigger increase in speed was noticed switching between portrait and landscape views, it changed from about 4 seconds to less than 2 seconds for a no group of all 9800 books.

I didn't notice the clean database and I'm not sure what it does. I ran it and it completed fine in a timely manner.

I went ahead and tried to remove all books from my library via calibre and it was excruciatingly slow. Deleting a massive quantity of books isn't something done often. I decided to stop the mass deletion by killing calibre and CC. Good news is that the database survived fine with only the books removed that had already happened before killing it.

I then removed all of the books using an android file manager and ran missing books. It was running fine, but again it will take forever to remove each book from the database using this method.

Instead I deleted the data and cache and started fresh with the app. Sending books to the device seemed fine. I sent in consecutive jobs of 500, 500, 750, 750, 1000, and 1000. All of these jobs seemed to be running faster than the previous version. Instead of 10 minutes per 1000 it was between 7 and 8 minutes per 1000. I then experienced a glitch that lost communication between calibre and CC. I don't have the error due to my computer attempting to shutdown for an unknown reason unrelated to calibre.

I then was left with 4830 books, so I decided to send them in one bunch. At the conclusion of sending the books to my Nexus, calibre said it timed out communicating to the device. I looked at my Nexus and CC seemed to be stuck on receiving the last book. I did have an alarm clock alarm for around 2 minutes toward the end of this run, but when CC came back to the front it seemed fine and the xfers were continuing.

In my impatience I swiped out the app. When restarted and connected to calibre it was about 200 books short. I tried to send one book and got the Free Space error. I knew there was space so I disconnected and restarted my device. I started CC and all of the books were present.

I don't know how much work CC does when books are sent to it but obviously it seemed to be busy processing the database? Hopefully you can make sense of my poor documentation of what happened.

Bottom line is it sent those 4800 books quicker it than it did previously.

Additionally when connecting to calibre, previously the throughput for the metadata sent would start out about 9Mb/s then slowed as it went finally ending up at about 3Mb/s. With the update the throughput remained relatively constant, it started around 9Mb/s and finished in the same range.

[Sefiriot]

Did a big transfer last night; it timed out before the metadata could get across, though all books were present and having "scan" turned on got them matched up nicely with calibre the next time CC connected.

Metadata sending from CC to calibre is moving at a good clip; I think it's faster now even with >10k books than previously with 7k. I suspect the previous slowdowns were from a potentially corrupted database.

I second DoctorOhh's observations: changing groups is definitely much faster. Under certain conditions however, switching back and forth from groups to no group results in a noticeable period with a blank white screen, particularly if I'm coming back to CC from another app.

Attaching logs for the last two sessions. CC database holding steady at 172MB so far, before and after cleaning the database. I wonder what's the growth rate per book?

[DoctorOhh]

Originally Posted by Sefiriot

Did a big transfer last night; it timed out before the metadata could get across, though all books were present and having "scan" turned on got them matched up nicely with calibre the next time CC connected.

I just did another complete book load from scratch, all 9830 books in one shot. It appeared to complete fine, but at the end when calibre reported complete calibre timed out as Sefiriot describes. CC on my Nexus also was stuck at receiving the last book. I left CC alone with the receiving message on the screen for 25 minutes and it didn't change. I restarted CC and it showed 400 books short of what was expected. If I had scan books checked it might have picked up the books on connect. But I had to send 387 books back to my device. At the conclusion it again timed out. I reconnected and sent the 159 of the last 160 books and it again timed out but just barely because CC cleared the last book shortly afterward.

If it is a matter of waiting until CC processes the books after receiving them then maybe a modified last book received indicating such would be a good idea. Alternatively having CC set to scan books on connect may be advisable for when you are loading books.

Truthfully it doesn't bother me because getting books loaded is a one time thing. My device is encrypted, I don't know if that makes a difference. Just for fun I'm doing a factory reset and trying again.

Bug Report: The Cleaning database. Please wait... dialog disappears if you move from portrait to landscape. At that point you don't know if it is still running.

[chaley]

Originally Posted by Dhevi

I hope you don't mind if I piggyback on your thread Sefiriot, but my question will somewhat tie in with the thread topic.

For Calibre Companion: when downloading files to the default directory it will store the ebook in the default directory, and based on folders by author like calibre does.

Will moving the files into created folders to organize by author name have any impact on CC as the library grows in size stored on the device. Where instead of simply scanning just the default directory, now CC is tasked with scanning the subfolders as well...

I am not sure what you are asking.

When downloading books, CC uses the path components supplied by calibre unless the "Use book ID as file name" preference is set. The path components supplied by calibre are controlled by the template in the SmartDevice App Interface plugin. If you change this template, CC will put new books where the template indicates. If you resend a book, CC will put it where it used to be to avoid creating duplicates.

When CC scans for books, it scans the entire folder hierarchy.

Have I answered your question?

[chaley]

@DoctorOhh and @Sefiriot:

Regarding the long send and the timeout:

I know why this is happening, and it is very surprising to me. The old implementation used a passel of tasks (threads), one per book, to update the database. This created a lot of contention, slowing things down and potentially creating problems. The new implementation uses a queue for requests to update the database for a book, ensuring that CC writes one book at a time to the database.

What we just learned is that the network is a *lot* faster than the database, as least in certain situations. What you are seeing is the queue getting so long that it cannot finish writing the books to the database in the 60 seconds that calibre is willing to wait. From my timing tests I thought that would require CC to get more than 200 books behind, which I thought was impossible. Well, apparently it isn't.

I will fix this by not permitting the queue to get longer than X, probably 4 or 5. If it gets that long, CC will wait for a book to get to the database before it adds another to the queue. This will slow down the apparent network transfer speed, but will ensure that when the transfers finish there isn't minutes of work left to do. @DoctorOhh, this will restore the network slowdown you previously saw, but I hope to a lesser degree.

Regarding the bug in the cleaning progress dialog: thanks. I have fixed that.

Regarding the speedup in grouping: this must be "caused" by the database clean because I made no changes in that code. The cleaning process creates a new database with everything packed together in a nice order and all empty space released. My guess (close to a certainty) is that the "nice order" is permitting the database queries to run substantially faster, giving you the performance improvement.

Finally, I am adding the ability for CC to write its own debug log. There will be a preference that when checked causes CC to log *lots of stuff* to the file calibre.companion.debug.log.txt in the root folder of the device public storage. It is there because where logging happens I cannot get any application-specific configuration, so I can't put the file into CC's default books folder. Oh well...

[DoctorOhh]

Originally Posted by chaley

I will fix this by not permitting the queue to get longer than X, probably 4 or 5. If it gets that long, CC will wait for a book to get to the database before it adds another to the queue. This will slow down the apparent network transfer speed, but will ensure that when the transfers finish there isn't minutes of work left to do.

Seems reasonable to me since loading the books is a one time thing.

The one thing that bugs me is on the calibre side, it took 40 minutes for the 9800 book job to enter the queue then 45 more minutes before the books started to transfer. But again since it is a one time thing it isn't a problem.

Update:It turns out the slow time mentioned above was due to disk intensive jobs I was running at the same time. The actual time is a more acceptable 15 minutes for the 9800 book job to enter the queue then 20 more minutes before the books started to transfer.

Originally Posted by chaley

@DoctorOhh, this will restore the network slowdown you previously saw, but I hope to a lesser degree.

The network slowdown I noticed was during the uploading of the metadata from my device to calibre. Something you did smoothed out the metadata upload in this build.

Originally Posted by chaley

Regarding the bug in the cleaning progress dialog: thanks. I have fixed that.

Glad I could stumble over something that could help. I say stumble because the tablet slipped out of my hand and I noticed the results.

Originally Posted by chaley

Regarding the speedup in grouping: this must be "caused" by the database clean because I made no changes in that code. The cleaning process creates a new database with everything packed together in a nice order and all empty space released. My guess (close to a certainty) is that the "nice order" is permitting the database queries to run substantially faster, giving you the performance improvement.

It was already fast that's why I said subjectively it seemed faster.

Originally Posted by chaley

Finally, I am adding the ability for CC to write its own debug log. There will be a preference that when checked causes CC to log *lots of stuff* to the file calibre.companion.debug.log.txt in the root folder of the device public storage. It is there because where logging happens I cannot get any application-specific configuration, so I can't put the file into CC's default books folder. Oh well...

Sounds valuable for future optimization.

[Dhevi]

Originally Posted by chaley

I am not sure what you are asking.

When downloading books, CC uses the path components supplied by calibre unless the "Use book ID as file name" preference is set. The path components supplied by calibre are controlled by the template in the SmartDevice App Interface plugin. If you change this template, CC will put new books where the template indicates. If you resend a book, CC will put it where it used to be to avoid creating duplicates.

When CC scans for books, it scans the entire folder hierarchy.

Have I answered your question?

Thank you. In a sense you have answered my question.

I've configured to SmartDevice App Interface plugin and it is working as desired when connecting as a Wireless device and Sending to Device from Calibre, but I've noted that the same is not true when connecting to Content Server and downloading from within CC. I've not been able to find information as to if this is configurable to store files with the template: {author_sort}/{series}/{title}.

[Sefiriot]

Here's another log testing CC 3.0.6. This time the transfer was about 1k+ titles. Interestingly metadata did finish sending this time before calibre timed out.

Since this is yet another monster log at 1.05 MB and over forum limits, it's again in my Dropbox.

I think that the "scan on connect" feature is beginning to having a more noticeable adverse impact during the initial handshaking period when CC and calibre are syncing up, now that the ondevice library's gotten this big (11560 titles).

Ondevice database was at 199MB after this transfer before cleaning. Size after cleaning remains at 199MB. Took about 30+ minutes.

I'd also like to report something strange: CC had been open since the file transfer (at least, not stopped) for several hours. Th phone of course had gone to sleep in between.

I then started CC's cleaning function. It brought up the "wait" dialogue screen which almost instantly disappeared and didn't clean the database. I then did a force stop and restart through device settings, told CC to clean the database, and all went back to functioning as usual. Possibly my device is just having a hiccup in functioning, but I thought you should know.

[DoctorOhh]

Originally Posted by Sefiriot

I then started CC's cleaning function. It brought up the "wait" dialogue screen which almost instantly disappeared and didn't clean the database.

If you tilted your phone a little and it slipped to landscape mode then the dialogue disappears even though the clean database function did not stop and is still functioning. The fix will be in the final release as well as the fix for calibre timing out after a large transfer.