strange "cannot download" bug - may relate to recent changes

[stumped]

cc v4.4.1 amazon store version so updated feb 2019( the store description says)
on a fire HDX tablet.

[ the 4.4.4 1 is correct for sure but with 2 stores on the tablet is is sometimes confusing which store delivered the app , and i thing for historical version I own copies on both stores- so it is just possible that its the google store version if that has the same version number ]

what started to happen was books would not download when CC was connected to content server: after a long press to download the icon would spin a while then I got a message - something like "cannot download [file name ] to device memory " or maybe it said " to device storage...

BUT it was only happening where i had deleted a book from the device and was now trying to get an updated version from content server.

my books go to a download/cc folder. there is no SD card in this device. it has over 1Gb free space. the epub is ~1Mb

when I tried several other books, not previously downloaded, they were all Ok- and appeared immediately. so the connection was good

so I now had 2 books that would not download, plenty of others that would....
troubleshoot steps:
1. stop start CC app. did not help,
2. power cycle device. did not help
3. stop and restart of calibre on PC seemed to resolve it

so I dunno if its the issue about calibre having now to hand off the book to reader app in android, or if it is a side effect of the fix that Kovid recently did to get the content server to always serve the latest version, after a recent edit, and not anything cached..?

the fire tablet is and oldish hdx so probably running OS 5. I can check if that is a factor

its more likely to be in calibre - i.e. CC is asking for a book and calibre content server for some reason is looking to a cache location where it is not present ? [ do to a change Kovid made a few weeks ago, in response to another thread ]

I am not sure how to try to recreate it, or even whether to bother, but I wanted to log it here in case the error message is a clue and I am missign an obvious an explanation.. i could not remember where to find the deviceapp logs of if they would help retrospectively or not.

FYI I think I edited this book yesterday, wanted to update the device version today, but calibre and the PC has only slept, not shut down in the interim

also, I have 2 tablets, I am pretty sure I updated the book on the other tablet yesterday with no issue, with the same workflow: remove from and delete from Moon+ , then delete from CC also, then connect, download....


UPDATE i found debug log - a very long file.. and I found the errors.

i see it is asking for the epub, then saing content server downlaod failed, java.io IOException format does not exist
but I can inspect calibre library and see it! and as I said above, a stop start of calibre fixed it ?. I can see in the same log, the request which then worked to fetch the book.

[theducks]

Run Library Maintenance in Calibre (and fix the indicated errors)

That message conflicts with what you observed, therefore, calibre (the db) lost track that it had an EPUB OR someone placed it there directly (a No No, You must use one of the official Add methods)

[stumped]

i did try to stage a reconstruction doing what I though was the trigger sequence but I could not reproduce it.
it is not a library maintenance thing though, library check reports no errors.
if you re-read the report, what transitioned from fail to find the book to successfully downloaded was simply stop then start calibre [ That was also the workaround when content server did not serve up the most recent edit a few weeks back].

but think it through: I connected with CC to content server, and asked it to find books with a given title. then I asked it to download one of the books it had found. so it was a case of It saw the book, but could not download the forat ??? if I asked instead to see the metadata, that displayed OK. there is only 1 format in the library - EPUB.
I attach the CC debug log that i saved, just in case that helps. that log is weeks long so look only at today and look at attempts to download a book called the Passage.
all that changed between getting the errors, and getting the download to work was stop start content server

[stumped]

updates:
so writing that last reply make me curiouser.
so I extracted only today from the debug log and began going through it.
1st puzzle is this:
2019-03-11 06:30:34.418: ContentServer: returning fixed values: ipaddress=192.168.0.72, port=8080
2019-03-11 06:30:34.479: Analytics: (true:true) cat=Connection, act=Connect Content Server, lab=CS Connect
2019-03-11 06:30:34.488: ContentServer: creating connection to http://192.168.0.72:8080/
2019-03-11 06:30:34.664: Error decrypting. Probably using wrong key.
dunno if that is significant ?

it repeats . each time there is a new connection made

PLEASE NOTE what i reported the error as " format does not exist"
that was not a full sentence . it goes on to say:
java.io.IOException: Format does not exist
at com.multipie.cclibrary.Opds.c.a(Source:57)
at com.multipie.cclibrary.Opds.f$a.run(Source:112)

WHY IS IT LOOKING THERE ???

now there is a new connect[ same wrong key error message...
i select book in a category ( read=i). i try a couple of times to download the passage and it fails.

i try a different book in same category - a painted house - that also fails - save error
Feedparser got category string calibre-category:#read:18
2019-03-11 09:34:55.121: Opds DataManager addData: start=0, finish=9, url=/opds/category/2372656164/4931383a2372656164?library_id=Calibre_Library
2019-03-11 09:34:55.122: OPDS FeedParser: before add change listener. showPosition=0, showOffset=0, LV count=0, manager count=10
2019-03-11 09:34:55.122: OPDS FeedParser: before notifyDataSetChanged
2019-03-11 09:34:55.296: OPDS FeedParser: before remove change listener and post
2019-03-11 09:34:55.316: OPDS FeedParser: in post before setSelection
2019-03-11 09:34:59.298: Download queue: try to download 6e633c5a-ae1a-4b5c-997f-06790437a127 The Passage
2019-03-11 09:34:59.320: OPDS downloadMetadata: UUID=6e633c5a-ae1a-4b5c-997f-06790437a127, filename=, dc=false
2019-03-11 09:34:59.320: OPDS Download: url=ajax/book/6e633c5a-ae1a-4b5c-997f-06790437a127/Calibre_Library?id_is_uuid=true
2019-03-11 09:34:59.352: filename value template value
2019-03-11 09:34:59.359: checkLpathComponents started The Passage - Justin Cronin w/URI=true
2019-03-11 09:34:59.422: checkLpathComponents finished The Passage - Justin Cronin
2019-03-11 09:34:59.424: OPDS downloadMetadata: UUID=6e633c5a-ae1a-4b5c-997f-06790437a127, filename=The Passage - Justin Cronin.epub, dc=true
2019-03-11 09:34:59.424: OPDS Download: url=ajax/book/6e633c5a-ae1a-4b5c-997f-06790437a127/Calibre_Library?id_is_uuid=true
2019-03-11 09:34:59.436: filename value The Passage - Justin Cronin.epub template value The Passage - Justin Cronin.epub
2019-03-11 09:34:59.437: OPDS downloadFile: url=/get/epub/5651/Calibre_Library, filename=The Passage - Justin Cronin.epub
2019-03-11 09:35:08.533: ContentServer: download failed
java.io.IOException: Format does not exist
at com.multipie.cclibrary.Opds.c.a(Source:57)
at com.multipie.cclibrary.Opds.f$a.run(Source:112)
2019-03-11 09:35:08.542: Log flush
2019-03-11 09:35:08.564: OPDS: download failed: The Passage
2019-03-11 09:35:13.596: Download queue: try to download 6e633c5a-ae1a-4b5c-997f-06790437a127 The Passage
2019-03-11 09:35:13.603: OPDS downloadMetadata: UUID=6e633c5a-ae1a-4b5c-997f-06790437a127, filename=, dc=false
2019-03-11 09:35:13.603: OPDS Download: url=ajax/book/6e633c5a-ae1a-4b5c-997f-06790437a127/Calibre_Library?id_is_uuid=true
2019-03-11 09:35:13.626: filename value template value
2019-03-11 09:35:13.627: checkLpathComponents started The Passage - Justin Cronin w/URI=true
2019-03-11 09:35:13.674: checkLpathComponents finished The Passage - Justin Cronin
2019-03-11 09:35:13.675: OPDS downloadMetadata: UUID=6e633c5a-ae1a-4b5c-997f-06790437a127, filename=The Passage - Justin Cronin.epub, dc=true
2019-03-11 09:35:13.676: OPDS Download: url=ajax/book/6e633c5a-ae1a-4b5c-997f-06790437a127/Calibre_Library?id_is_uuid=true
2019-03-11 09:35:13.692: filename value The Passage - Justin Cronin.epub template value The Passage - Justin Cronin.epub
2019-03-11 09:35:13.693: OPDS downloadFile: url=/get/epub/5651/Calibre_Library, filename=The Passage - Justin Cronin.epub
2019-03-11 09:35:22.768: ContentServer: download failed
java.io.IOException: Format does not exist
at com.multipie.cclibrary.Opds.c.a(Source:57)
at com.multipie.cclibrary.Opds.f$a.run(Source:112)
2019-03-11 09:35:22.778: Log flush
2019-03-11 09:35:22.784: OPDS: download failed: The Passage
2019-03-11 09:35:29.752: Download queue: try to download 3f9aee78-873c-44d3-9f86-7c18c87c71f8 A Painted House
2019-03-11 09:35:29.759: OPDS downloadMetadata: UUID=3f9aee78-873c-44d3-9f86-7c18c87c71f8, filename=, dc=false
2019-03-11 09:35:29.759: OPDS Download: url=ajax/book/3f9aee78-873c-44d3-9f86-7c18c87c71f8/Calibre_Library?id_is_uuid=true
2019-03-11 09:35:29.807: filename value template value
2019-03-11 09:35:29.812: checkLpathComponents started A Painted House - John Grisham w/URI=true
2019-03-11 09:35:29.867: checkLpathComponents finished A Painted House - John Grisham
2019-03-11 09:35:29.868: OPDS downloadMetadata: UUID=3f9aee78-873c-44d3-9f86-7c18c87c71f8, filename=A Painted House - John Grisham.epub, dc=true
2019-03-11 09:35:29.869: OPDS Download: url=ajax/book/3f9aee78-873c-44d3-9f86-7c18c87c71f8/Calibre_Library?id_is_uuid=true
2019-03-11 09:35:29.885: filename value A Painted House - John Grisham.epub template value A Painted House - John Grisham.epub
2019-03-11 09:35:29.886: OPDS downloadFile: url=/get/epub/5654/Calibre_Library, filename=A Painted House - John Grisham.epub
2019-03-11 09:35:38.944: ContentServer: download failed
java.io.IOException: Format does not exist...

and on it goes, some work, some fail... and eventually it gets to what the earlier posts describe. All OK but only after a stop start of content server

skip forward in the log and here is where it worked ok
same UUID as above and same calibre Id 5651

2019-03-10 08:38:50.746: Download queue: try to download 6e633c5a-ae1a-4b5c-997f-06790437a127 The Passage
2019-03-10 08:38:50.767: OPDS downloadMetadata: UUID=6e633c5a-ae1a-4b5c-997f-06790437a127, filename=, dc=false
2019-03-10 08:38:50.768: OPDS Download: url=ajax/book/6e633c5a-ae1a-4b5c-997f-06790437a127/Calibre_Library?id_is_uuid=true
2019-03-10 08:38:50.785: filename value template value
2019-03-10 08:38:50.800: checkLpathComponents started The Passage - Justin Cronin w/URI=true
2019-03-10 08:38:50.890: checkLpathComponents finished The Passage - Justin Cronin
2019-03-10 08:38:50.891: OPDS downloadMetadata: UUID=6e633c5a-ae1a-4b5c-997f-06790437a127, filename=The Passage - Justin Cronin.epub, dc=true
2019-03-10 08:38:50.891: OPDS Download: url=ajax/book/6e633c5a-ae1a-4b5c-997f-06790437a127/Calibre_Library?id_is_uuid=true
2019-03-10 08:38:50.906: filename value The Passage - Justin Cronin.epub template value The Passage - Justin Cronin.epub
2019-03-10 08:38:50.906: OPDS downloadFile: url=/get/epub/5651/Calibre_Library, filename=The Passage - Justin Cronin.epub
2019-03-10 08:38:51.180: Book metadata downloaded: The Passage : 6e633c5a-ae1a-4b5c-997f-06790437a127

I CONCLUDE THAT I KNOW ONLY ENOUGH TO ADD TO THE CONFUSION HERE, SO I WILL LEAVE THE LOG POSTED & HOPE....

attaching the log extract for today only

[stumped]

Ps. On my other tablet I searched the cc log for that device and there are no instances of
error decrypting probably used wrong key...
after connecting to content server

I am now thinking that was significant and was a clue to why the download failed Which Chaley will understand...

I was not aware that Content Server to cc used encryption ?

[chaley]

I confess to confusion. "Format does not exist" comes from calibre. Why would a format come and go?

The encryption message is about the credentials used to connect to the content server. CC stores the username and password in an encrypted database. When you connect CC looks up the IP address/port in the database and uses whatever you used before. If connection fails then after you see this message CC should ask you for the correct credentials. If it does not then we are faced with the (impossible situation of) credentials are being accepted when you first connect but not later when you try to download the book.

The fact that restarting the content server makes things work strongly implies that the content server is not keeping track of cached formats. This is the sort of problem that I *really don't like* because they are often traffic and operation sensitive. That said, I will try to reproduce it using the detailed steps you provided.

As for "Why is it looking there?": that is an internal CC program trace. It means nothing to people in the real world.

[stumped]

Thanks for reply.
Afailk I have never used any user name and password setup for calibre . And There is no password needed to access my documents as a user in windows.
And only one of my two devices running cc has that decrypt key error mention in logs
So that is a minor puzzle but maybe not a cause.
Unless I misread the log sequence that decrypt error comes before any books are requested. It is part of the initial set up of the connection ?
And it was there just once per session, of once per book request.

My own quick try to reproduce the issue failed. I edited a book again in calibre then asked for it via content server and it was served ok. It did not go missing!

I know that kovid added something recently. To content server. It is in his release notes. It says try to check if file has been edited outside of calibre and serve the latest version. I edit in sigil.. I don't know how he implemented that though so I don't know if that could be a factor ?
But because the download failed for two different books, I can't think of a cause. There is no way I would ever have had both books left open for edit or in use in another program.
The second bookwhich did not download,. A painted house, had not been recently tweaked. I tried it after the first download failed because it was the next title on screen in that category.
Then I think I tried some others which worked, so then went into stop, start cc, restart tablet etc.
Please don't some too much time on it. It may have been a one off glitch with calibre that will never get explained. It probably doesn't not help that I leave calibre running or idling for weeks, and only shut it down if there is a problem or if windows wants to upgrade. I just sleep the pc with calibre still running.
In calibre I think there were epub and original epub files for those books. So only one valid format.

[stumped]

just for the record, and to close this off. I have made several more changes to the book I was working on ( it is a purchased epub game guide from gamepressure.com ) correcting bad English and removing unnecessary bits . So I have several times deleted it from tablet and from CC's records and re-fetched it from content server after editing it on PC. That has worked every time. I am unable to replicate the cannot download format error.

also for the record, the issue of content server serving a cached copy still happens.
i.e. if you have sigil as your default epub editor, double click a book title in calibre main window to edit it, and save it from sigil after editing [ which returns it to its original place in the library ] - after that has completed, the content server gives out the previous version, [ which no longer exists in the library because it was overwritten by sigil a few minutes earlier. this continues to happen until calibre is fully closed and then restarted.

[chaley]

for taking the time to document the problems. I am not sure what to do with the information, but it could easily be helpful to someone who runs into the same problems.

[stumped]

I didn't want you to be trying to trace something that cannot be replicated
as for content server cache, Kovid had already accepted the previous report and tried to improve it. so its just a case of remembering to stop start the server if you are in a repetitive, edit epub book, send to tablet for review,,, rinse & repeat cycle. [ probably a non issue if you use calibre editor anyway, but I am stuck in my old ways and I like using Sigil ]

one thought though. could there be a way to view debug log [ as a text file] added to the app, as finding stuff in android folders is so hard. [ and show the log in reverse i.e. in most recent to oldest sequence, as today's events are at the bottom of a very long text file ]?

[chaley]

Originally Posted by stumped

one thought though. could there be a way to view debug log [ as a text file] added to the app, as finding stuff in android folders is so hard. [ and show the log in reverse i.e. in most recent to oldest sequence, as today's events are at the bottom of a very long text file ]?

I am not sure I understand what you are asking for, but here goes...

You can email the CC debug log to yourself instead of to me. That gives you everything that CC records, in ascending time order. There isn't any way to reverse it, but that isn't much because all you need to do is go to the end and move backwards. Of course, there will be a lot of internal information you don't care about, but you can also see what CC does with downloaded books.

You can also fetch the current debug log as a file. It is in main memory at Android/data/com.multipie.calibreandroid/files/calibre.companion.debug.log.txt.

[stumped]

I I'd not think of emailing it to myself, which I could then receive on the device.
I was just thinking that when I, or another user, gets some connect to, or download error , it would be good to tap somewhere and bring up the debug log , for a possible clue