Wrong collections inserts after transfer to PRS-T1

Bug #986044 reported by Joachim Paetzold
30
This bug affects 5 people
Affects Status Importance Assigned to Milestone
calibre
Fix Released
Undecided
Kolenka

Bug Description

After transfer to PRS-T1 the new generated collections are empty.
The rows in the table collections have wrong data. The content_id value has no reference in the table books.

Calibre 0.8.48
Windows Vista

Related branches

Kovid Goyal (kovid)
Changed in calibre:
assignee: nobody → Kolenka (user-o)
status: New → Triaged
Revision history for this message
m4mmon (m4mmon) wrote :

Hello,
I have almost the same issue. Some collections are OK, some are empty, some contain unrelated books. Both internal memory and external SD are used, contain books and collections.
Calibre 0.8.48 / Windows 7

Revision history for this message
The-Bird (the-bird) wrote :

Hi
I've got the same problem. Both internal memory and external SD are used, contain books and collections. Only SD datas are erratic....

Calibre 0.8.48 / Windows XP

Revision history for this message
Kolenka (user-o) wrote :

In order to investigate, I will need books.db files from affected SD cards. They can be attached to this bug.

Revision history for this message
blorks (zemisterwhite) wrote :

Hello,
I encounter the same issues with collections. Some are empty, some contain wrong books, some contain entries with "Removing..." (clicking on it does not open a book, and it cannot be manually removed in T1 collection management).
I also use SD and internal memory.
In "sending books to devices" preferences panel, I use the "automatic management" for metadata because in most cases, after a few plugs/unplugs, collections end up right.
But if I add books or modify metadata in calibre, next time I unplug the T1, collections can end up with the described errors.
I provide here the books.db from SD. Everything is fine except the "Science Fiction" collection. It contains 6 books. 2 of them are listed as "Removing...".

Revision history for this message
The-Bird (the-bird) wrote :

Hello

Here is a corrupted booksdb from the main memory of the T... The "Potter" collection indicates books (which it should contain) but when opening that's a total mess with hundreds of SF books from both SD cards and main memory :-(

Sometimes it's that kind of flaw, sometimes it's empty directories, sometimes the 'retiring book" message...

Revision history for this message
The-Bird (the-bird) wrote :

Another faulty books.db from the sd card, displaying 70 books instead of 40 in the collection "La Compagnie des Glaces". When opening the collection, the 30 inexistant books appear like "retiring now"

Hope it can help

Revision history for this message
The-Bird (the-bird) wrote :

Hi

Is there any news about this annoying "messed up collections" bug ???

Revision history for this message
blorks (zemisterwhite) wrote :

Yeah, now using 0.8.51, problem still there.
Just did that: I removed all SD collections in the T1 though embedded collection management, then plugged it to my computer. After calibre ended sending metadata, I properly unplugged the T1 from my computer. This time *all* SD collections were empty, no "Removing..." entries or other fuckup. I replugged the T1, and after that, this time everything was fine.
So one cannot rely on collection management for the T1.
In my case, internal memory collections are not affected (or I never realized it).
What can we do to help you solve this issue ?

Revision history for this message
The-Bird (the-bird) wrote :

I've just tried your trick, blorks, but it's worst than ever. Every collection had been recreated with errors, omission, some books are "removing now", there are collections with books from both memory and sd cards...

I'm really sorry that Calibre is not able to send collection properly to the T1... :-(

Revision history for this message
antonio623 (tricoci) wrote :

Hello i write from italy, i have your problem with calibre and sony prs t1, for two month all is ok, now collection on SD are empty, with sony reader all is ok, but this software don't like me.
There's is solutions?
bye bye antonio

Revision history for this message
blorks (zemisterwhite) wrote :

I am feeling desperate, we have provided books.db files etc as asked and we don't have any feedback from developer. There are at least 2 threads on mobileread forum about this :
http://www.mobileread.com/forums/showthread.php?t=178633
http://www.mobileread.com/forums/showthread.php?t=163174

I provide here another books.db, even if I feel that no one looks at this bug.
I am no coder or anything, but I just had a look at the database after adding a new group of books that belong to the same collection on the sdcard. And if everything was fine with existing collections, the new one was broken.

So, in database:
- the new books are fine,
- the new collection is fine,
- the contents of the collection is fucked up : id of collection and books are very low...

My conclusion is that adding the delta for high ids for *sdcard* is not done in *some* cases in T1 plugin.
If I edit this database, and add 4294967296 to collection_id and content_id columns values for rows (4294967339, 4294967344) everything is fine...

Please please please developers : reproducing the issue is easy. Simply start from a clean device and SD, and add books to both media, some collections will be fucked up.

Revision history for this message
blorks (zemisterwhite) wrote :

I think I might have solved the issue, I have modified some stuff in src/calibre/devices/prst1/driver.py
At first I just displayed ids of collections and books : obviously everything is fucked up at creation time when sending to external sd.
Then I tried to modify ids when necessary (sd and id below big number)
It seems to work for me.
I am no developer so this might be even worse than today etc.

Revision history for this message
Kolenka (user-o) wrote :

I'd like to note that I am not a Calibre developer, nor do I really have a lot of time to contribute to projects like this. I'm just the poor sap who had some spare time half a year ago to write the initial driver and is now expected to provide support for it. The team is now punting all T1 bugs my way, and I don't have much time to actually tackle them. And it gets worse, I don't actually have an SD micro card currently available to even reproduce these issues to, even though its obvious what the problem is from the SQLite DBs.

As for the proposed fix, it does do something I intentionally tried to not do: retroactively change Ids. It does address some of the issues, sure, but it carries the risk of corrupting the DB with unintentional edits.

The driver already has something that is meant to prevent this problem, but it is only partially working in the case of the second and third DBs provided in this bug.

Before I dig too much into this trying to get everything together to create my own debug environment, I have to ask: In any of these situations did you try to use 0.8.51 or later after erasing the SD card from the device's UI?

I also need to check the history on this file since it seems like devs on the team /have/ made changes that are wrong/conflicting.

Revision history for this message
blorks (zemisterwhite) wrote :

Yeah ! I understand your situation Kolenka. And my proposed change was a desperate one, I understand that these are not safe at all, I tried to cure the symptoms, not the actual issues.
I will try to clean and retry everything like you suggest, ASAP, but I think that will not change anything.
And now that I have a development environment, I will also try to see why the inserted id are wrong since the values differ from the actual values inserted in books and collection tables, may be it will help.

Thank you anyway for your answer, and please accept my apologizes if you felt offensed by my words.

Revision history for this message
Kolenka (user-o) wrote :

The root problem of this particular bug is already known, this is just one symptom of the same root cause I've tried to address twice now. The T1 doesn't correctly initialize the SD card's DB when it creates it, which can result in weird behavior if a 3rd-party app assumes that the SQLite DB is valid (specifically, the T1 needs to initialize the sqlite_sequence table).

The latest fix I did will correctly patch the sqlite_sequence table before writing any data out to the database. *However*, the catch is that it doesn't work if the DB is already in a bad state, since your existing books/collections will have bad Ids.

The reason I ask that you try this is because the answer reveals something very important about the behavior.

- It works: The driver is handling 'new' devices correctly, which means my fix works as intended. But it means that I probably need to think harder about how to fix the DB if it is already corrupted, since people are hitting that.
- It doesn't work: The driver isn't handling 'new' devices correctly, which means my fix isn't working as intended, and I need to rework the whole fix.

If it is the first case, that saves me a *ton* of time. I don't have to second guess that particular part of the driver, and can focus on something that will 'recover' corrupted DBs a bit better.

Revision history for this message
The-Bird (the-bird) wrote :

Hello

So if I understand well, you would appreciate that we erase the books.db files from the device and SD-card and let Calibre rebuilt them ?

(I doubt it'll do it good, because I've done that before, but I will do it if it's really useful for you...)

Thank you very much for the time you give for the fix...

Revision history for this message
blorks (zemisterwhite) wrote :

So I formatted the SD card.
Then sent books from calibre 0.8.53.
All collections were empty.
Since I use automatic metadata management I plugged the T1 then unplugged it : all collections were fine.
Then I sent another book that belongs to existing collections : each of the modified collections contained one "removing..." entry.
After a new plug/unplug cycle (to refresh metadata) : previously modified collections contained all expected volumes, but "removing..." entry was still there.

I am sorry, but I think we are in the second case.

Revision history for this message
blorks (zemisterwhite) wrote :

I think the problem might be simpler than that. The existing sequence fix is OK for me.

But after inserting a book or a new collection, cursor.lastrowid is read to associate the id to the new book/collection. But it is completely different from the "id" column and the problem comes from here.
I added some print statement in the dev environment to prove that.
I will try to read the new "id" value by issuing a select statement, I am pretty confident it will fix all issues.

Revision history for this message
blorks (zemisterwhite) wrote :

I think I was right in my previous message.
You will find attached another modified driver.py. The code is as bad as the previous one, but this time I get actual id by performing a select just after the collection (and book) insertion. It is just provided here as a demonstration, not as a patch.

It only works with clean collections (i.e. no collections at first execution, since "removing..." entries won't be cleaned).
I tested it by randomly adding/removing books then checking result, and it seems to work perfectly.

From what I have read and experimented with some sqlite GUI tool, rowid and id should be the same, so the existing code should be *completely* correct, but cursor.lastrowid returns a bad value : may be this is a bug in sqlite3 ?...

Revision history for this message
Kolenka (user-o) wrote :

Interesting if this is actually working.

Can you grab the debug spew from the command-line that shows this behavior and attach it? You've got plenty of good data in there, and I'd be happy to look it over. Seeing it would help me confirm what you say, but it is making perfect sense, and gives me a good jumping off point once I see your debug spew.

What I suspect is happening is that my edits to the sqlite_sequence table are introducing the bad behavior. It "works", but screws up the cursor, which returns bad lastrowid values. These lastrowids might just be a "guess", and the lack of any commit is screwing things up.

I've also got something in the works that should be able to correctly "fix" bad DBs retroactively without much risk. I'll be doing that work tonight. If you can provide the debug spew in say, the next 8 hours or so, I'll have it in time for my work and can integrate your work/investigation into mine.

The fix you have is actually pretty decent, although a bit more "chatty" than what should probably go out to users. And I think I may have a couple ideas that avoid the need for the extra select statement that I'd like to try. :)

Revision history for this message
blorks (zemisterwhite) wrote :

Of course I can !
Here you will find traces and corresponding database.
I started with an existing database; I removed all books and collections (from the PRS-T1 itself).
Then plugged it, added some books, removing some, unpluging, pluging again, adding/removing etc.
#986044 is in great progress, thank you very very much !

Revision history for this message
Kolenka (user-o) wrote :

I made some time tonight to take a look at this. Nuked my T1's DB pretty well in the process though. I probably should have backed it up before letting my driver changes puke all over it.

The issue was that when the sqlite sequence was being mucked with, it didn't affect currently open cursors to the DB. A simple fix would be to simply close and reopen the cursor after making this sort of edit.

Instead, I decided to tackle the whole process of how it does this workaround for the PRS-T1 bug (where it is not setting the sequence right before Calibre sees it). Now, when writing out the metadata, it will actually ensure that anything written to the SD card has the right set of Ids. If an Id for the SD card is wrong, then it will go ahead and repair the DB. It should even make sure that annotations/bookmarks/font choice come with, although it is unlikely that will happen in real situations.

Crossing my fingers that this finally is a complete work-around for the ridiculous T1 behavior that required it in the first place.

Revision history for this message
Kolenka (user-o) wrote :

Crud, the patch needs tabs converted to spaces for things to look right. Gah.

It is late here, so I won't get to it tonight, but if it can be done as part of applying the patch, the devs would have my thanks.

Revision history for this message
Kovid Goyal (kovid) wrote :

Here's a cleaned up patch, with a few fixes for missing imports and the like. I'd appreciate it if some of you with T1s could test it, before I merge.

Revision history for this message
Kovid Goyal (kovid) wrote :

The full driver.py for those of you that dont know how to use patches.

Revision history for this message
The-Bird (the-bird) wrote :

Sorry for being such an ignorant, but I don't have any notion of dev, so where do I put this driver.py to see if your awesome work works ??

Revision history for this message
Kovid Goyal (kovid) wrote :

Follow the instructions here: http://manual.calibre-ebook.com/develop.html#windows-development-environment and replace the file devices/prst1/driver.py

Revision history for this message
blorks (zemisterwhite) wrote :

I just tested the new version of the driver with 0.8.53.

What I did :
- formatted SD from T1
- started calibre *without* the patch in order to create fucked up collections : got empty ones
- still *without* patch, plugged and added a new book : got a "removing..." entry in a collection
- started calibre *with* the patch , let in refresh metadata in the T1 : collections contain every expected book, but "removing..." entry was still there.
- plugged the T1 once again, removed a book on the SD, and added it again : got two "removing..." entries this time in the collection.

- removed all SD card collections (from T1)
- plugged the T1, let the metadata refresh : got empty collections
- plugged the T1 once again, added a new book : got a "removing..." entry in a collection

- formatted SD card from T1.
- plugged T1 and added books : all collections were fine
- plugged T1 added and removed books : all collections were fine
- removed all SD collections (from within T1)
- plugged T1, added a book : all collections were fine
- *BUT* database inspection shows that all id are low ones...

Conclusions :
1/ Repair feature did not work with my scenario.
I added some print statements and saw that "sequence_dirty" flag is not raised : if I understood the code, if books.id is "broken", then all tables will be repaired. But as previous analysis shown, id were all ok in database (for books, collection and collections), so repair procedure is not triggered.
A remark : I believe in the repair procedure, but the "sequence_dirty" flag has to be raised when needed (not only *.id, but also with collections.content_id and collections.collection_id).

2/ Collection management still broken with existing database.

3/ Starting from a fresh database seems to work BUT all ids are low ones, I don't know which side effects it will cause. I thought that there would be a mixup with internal/SD books when opening : my tests showed that it does not seem to happen : I opened book with "conflicting" ids from collections and from book list, no mixup happened.

So even there is no success, thank you for your work, we see that there is progress and hope you will not give up.

PS : I hope another tester confirms that, I don't want to be the only one to test... Setting up environment is easy once you guess how to deflate this xz file :)

Revision history for this message
Kolenka (user-o) wrote :

The repro steps are a bit hard to follow. Can you provide new books.db files?

Revision history for this message
blorks (zemisterwhite) wrote :

There are three parts in the steps, but like you said, the comment formatting makes it hard to follow...

First part : creating "bad" database with unpatched calibre, then launching patched calibre : the idea was to see if repair procedure is working.

Second part : still using same database and patched calibre, but starting with no collections at all : the idea was to see if collection management was working.

Third part : brand new database and patched calibre : the idea was to see if collection management was working like in step #2, but without any history in db.

The attached books.db file is the one resulting from the third part : brand new DB, added books, etc. with patched calibre.
Everything seemed to work, but all ids are low ones.
I checked several times if I was not inspecting internal storage DB, believe me this one comes from SD card.

Revision history for this message
Kolenka (user-o) wrote :

D'oh, integer overflow typo. I tested it by telling Calibre that the minimum Id for the internal memory should be around 700 million. But the SD card starts at 2^32, which overflows in 32-bit integers back to 0. I have to make sure to define the sequence numbers as long integers rather than standard integers. It also looks like 64-bit python builds may even have 64-bit ints, which would have made it even harder to find this typo. Yeesh.

I'll have an updated patch tomorrow morning once I apply it to Kovid's version of the patch.

Revision history for this message
Kolenka (user-o) wrote :

Okay, here's the cleaned up patch that merges/finishes the touches Kovid started making, an fixes a couple typos.

Revision history for this message
Kovid Goyal (kovid) wrote : Fixed in lp:calibre

Fixed in branch lp:calibre. The fix will be in the next release. calibre is usually released every Friday.

 status fixreleased

Changed in calibre:
status: Triaged → Fix Released
Revision history for this message
blorks (zemisterwhite) wrote :

Hello,
I am glad to see there is more progress on it, but for me it does not seem to work any better than previous version.

I am still using 0.8.53, with patched driver http://bazaar.launchpad.net/~kovid/calibre/trunk/view/head:/src/calibre/devices/prst1/driver.py (dating from 2012-06-04 04:25:47 UTC).

Step #1: Like previous test campaign, I first started with a "dirty" DB, no luck. I am pretty confident that the "dirty_flag" will never be triggered since with existing broken databases, since what was broken were ids in columns "content_id" and "collection_id" in "collections" table, not book ids.

Step #2: I then deleted all collections to see if it would be better (from T1), plugged the T1 : I ended with empty collections.

Step #3: Finally, I formatted the SD card, plugged the T1 and started adding books from calibre.

Conclusion : Like previous time, repair procedure does not work. Starting with empty database seemed to work fine, but ids are low ones.

I hope I do not raise a false alarm and did perform the tests properly. I added a few print statements to see what was going on, you will find attached the traces of step #3 along with the db.

Revision history for this message
Kolenka (user-o) wrote :

There are two parts to the patch. There is a part that corrects the books, and another to correct collections. You seem focused on the former that you are missing the part of the patch for the latter. The symptom you are reporting is part of a larger problem with how the Sony handles the DB. The fix I took is addressing the root cause, not just the one symptom.

If there is something wrong at this point, it would be that the driver is somehow not getting the right minimum sequence when it asks for it only for the SD Card and not internal memory. So I'll probably need to add more tracing to confirm that this is really what is happening, of it isn't a typo in the if (again).

Revision history for this message
blorks (zemisterwhite) wrote :

OK, I got it for the 2-part fix.
Can I do something to help you track that last issue with the sequence ? Since I can grab calibre debugging output in real conditions with SD-card, it might be useful.

Revision history for this message
Kolenka (user-o) wrote :

Try this patch. It contains yet another typo fix, and some debug spew which will provide some light on how things are getting patched. Things should be working fine for the most part. The logic is identical for internal memory and the SD card. The catch is that the logic 'asks' what the sequence's minimum value should be based on the source Id.

The logic that replies with the minimum value had a typo, and compared an int to a string for the SD card. Because of that, it always returned the minimum for the internal memory and off it went.

From the spew, it should be obvious what the patches are doing now.

Revision history for this message
blorks (zemisterwhite) wrote :

In get_database_min_id, I changed
if source_id == '1':
to
if source_id == 1:
Now, corrupted database is completely fixed after synchronization.
Still, when adding a new book and/or a new collection, there are still low ids inserted. They will be corrected at next synchro, but...

Revision history for this message
blorks (zemisterwhite) wrote :

Only saw your latest patch after my previous answer. I will try it ASAP and generate the traces.

Revision history for this message
Kolenka (user-o) wrote :

Are the low Ids only in collections and not books? If so, I think I see why that is happening (cursor being opened before the fixes are applied).

Revision history for this message
blorks (zemisterwhite) wrote :

Just tested your latest patch, same result as mine above.
Here is what I did :
- started with a "bad" database (all low ids).
- plugged the T1
- added two books (one is leading to the creation of a new collection, both will be added to an existing one).

New collection and new books have high ids, but like with "old" driver, collection_id and content_id in collections are low ones.

I provide traces and db as attachment of this comment.

After collecting traces, I replugged the T1 to see if collections will be repaired, but "dirty" condition is not met (since books and collections have high ids), books are added in collections, but bad entries remain in database.
I think this last point is important, because with old driver, everything had high ids, but insertions in "collections" were done with wrong values, and this situation does not trigger "dirty" condition.

Revision history for this message
Kolenka (user-o) wrote :

This is a second tweak to the fix, which addresses when the collection update opens a cursor.

Revision history for this message
Kolenka (user-o) wrote :

The dirty condition is looking for rows in the table that are given the wrong id, they aren't looking for orphaned references.

Unfortunately, I didn't even see the effects of these orphaned references + my fixes until just now (another effect of not having the SD card, joy).

The catch here is that orphaned references are simply unrepairable. The book/collection they are meant to point to can simply not be found. I'll make another small patch that cleans up these orphans after updating the database.

Revision history for this message
blorks (zemisterwhite) wrote :

... sorry but I replayed the exact same scenario as before, but insertion in "collections" is still done with low ids.

Revision history for this message
Kolenka (user-o) wrote :

"... sorry but I replayed the exact same scenario as before, but insertion in "collections" is still done with low ids."

I think there may be a communication problem because that isn't what is actually happening, so I get confused.

After these fixes, I can confirm that inserts are NOT using low Ids. However, existing low Ids are 'orphaned' and not being repaired. The answer is: they can't be repaired, they need to be removed.

Revision history for this message
blorks (zemisterwhite) wrote :

I understand it is difficult to detect/repair orphaned references. In fact, deleting collections and synchronizing the T1 will repair, so this is not "show stopper", as long as driver does not insert new ones :)

Revision history for this message
blorks (zemisterwhite) wrote :

Sorry I have not been clear about why I am saying that this is not completely working with the last "db tweak" :

I am starting with a "bad" database, everything has low id.
I am plugging the T1 : repair procedure is OK, database is now with high ids ==> OK

I add two new books : inserts in books and collection tables are done with high ids, but rows inserted in "collections" table is done with low ids for "content_id" and "collection_id" columns.
The same issue I was trying to fix with a "select".

Revision history for this message
Kolenka (user-o) wrote :

So here's the database cleaning routine + cursor patch.

Both should be merged into Calibre:
- T1Typo.patch
- T1Typo_part2.patch

That should leave things in a fairly clean state whenever you send a book to the device.

Revision history for this message
Kolenka (user-o) wrote :

Okay, something is weird going on. Because I can't actually replicate this behavior at all. It looks like a 32-bit overflow, but I'm not seeing the same 32-bit overflow happening. The values are coming out just fine.

Can you tell me more about the machine this is running on?

- OS, Version, 32/64-bit?
- Can you tell me if Calibre is running as a 32 or 64-bit process?

Revision history for this message
blorks (zemisterwhite) wrote :

I am running windows 7 x64 (windows 6.1 b7601 SP1), and calibre-debug.exe is running as a 32-bit process.

Revision history for this message
blorks (zemisterwhite) wrote :

Sorry I did not see your last "Updated Part 2 Patch", and don't have time to test it right now. I will only be able to test it in about 24 hours.
Thank you for all your efforts.

Revision history for this message
Kovid Goyal (kovid) wrote :

@Kolenka: Merged T1Typo.patch form post 37 and T1Typo_part2.patch from post 48. Ignored the patch from post 42 since it seems to be contained in 48

Revision history for this message
blorks (zemisterwhite) wrote :

I just gained some time and had a try to your "orphans" patch.

It is OK, the orphans are correctly removed.

However, like previously explained, new orphans are inserted when adding *new* books/collections to the T1.

But now thanks to this last patch, there is a workaround : with automatic metadata management, unplugging and plugging again the T1 fixes the collections.

Thank you for your efforts, you are almost there :)

Revision history for this message
Kolenka (user-o) wrote :

Urg, okay, sorry about this blorks, since it turns out that you are likely right that lastrowid is not returning the right value. It explains why I was chasing other behavior on my machine.

It looks like a 32-bit overflow. The likely cause would be in the layer that calls SQLite from Python. SQLite3 returns a 64-bit int, and python supports long integers, but I have to guess that the translation between native and python is getting throttled to 32-bits. I haven't seen it because calibre runs as 64-bit on my machines.

I'm playing with a replacement that should do the job.

Revision history for this message
Kolenka (user-o) wrote :

Alright, blorks, let me know if this patch does the trick. I've switched the use of cursor.lastrowid to a SQLite query that does the same thing.

Revision history for this message
The-Bird (the-bird) wrote :

I stay really quiet, because I don't have any dev notion, so I feel like a poor little earthling caught in a great wise aliens chat, but I read (with amazement) all your contributions and must thank you for all the work you put in these...

I'll wait for friday's update of Calibre with a lot of impatience to see my T1 sort all my collections without all the mistakes and retiring books...

Thanks again to all of you...

Revision history for this message
blorks (zemisterwhite) wrote :

Good news everyone ! The last patch to replace last_row_id is working fine !
As a conclusion :
The patches :
- repair a broken database (including removing orphans in collections, those annoying "Removing..." entries),
- do the job well with new books / collections

One good thing would be if someone could test it in real conditions as I do, in order to confirm what I am saying.
I also hope the last patch wil make it in 0.8.55 !

Thousands thanks and congratulations Kolenka ! Hip hip hip ! Hourra ! :)

Revision history for this message
Kovid Goyal (kovid) wrote :

patch is merged

Revision history for this message
The-Bird (the-bird) wrote :

Huge thanks to all of you !

To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Duplicates of this bug

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.