audiamus / BookLibConnect

A standalone Audible downloader and decrypter
GNU General Public License v3.0
701 stars 40 forks source link

Did The Library Stop Syncing/Resyncing For Anyone Else? #53

Closed Innogen closed 2 years ago

Innogen commented 2 years ago

Today, July 1st, the Library shows all books as being unavailable. A World Icon with a Red Slash mark shows in every single book in my Audible Library. The same happens when I resync. I also tried uninstalling and reinstalling. This is on Windows 10.

I was just wondering if anyone else was having this problem, or if I messed it up somehow?

audiamus commented 2 years ago

What does the log file say?

Teekeks commented 2 years ago

Fresh install, seems to not sync as well. Where do I find that log?

Teekeks commented 2 years ago

Found them @audiamus

02:42:23.910 0001 [ManageProfilesForm.loadProfilesAsync] >>> 
02:42:23.910 0001 [BookLibrary.GetAccountAliases] >>> 
02:42:23.913 0001 [BookLibrary.GetAccountAliases] #contexts=1
02:42:23.913 0001 [BookLibrary.GetAccountAliases] <<< 
02:42:23.913 0001 [AudibleClient.GetProfilesAsync] 
02:42:23.916 0001 [ManageProfilesForm.loadProfilesAsync] <<< 
02:42:30.693 0001 [ConvertDGVControl.btnDnload_Click] 
02:42:30.698 0001 [BookLibForm..ctor] Lena, de
02:42:30.712 0001 [BookLibForm.OnLoad] >>> 
02:42:30.712 0011 [BookLibrary.GetBooks] >>> ProfileId { AccountId = 1, Region = de }
02:42:30.713 0011 [BookLibrary.GetBooks] from cache, #books=0
02:42:30.713 0011 [BookLibrary.GetBooks] <<< ProfileId { AccountId = 1, Region = de }
02:42:30.748 0001 [BookLibDGVControl.setDataSource] #books=0 (deliv type filtered)
02:42:30.748 0001 [BookLibDGVControl.resetDataSource] #books=0 (filtered)
02:42:30.749 0011 [BookLibrary.CheckUpdateFilesAndState] >>> 
02:42:30.752 0011 [BookLibrary.CheckUpdateFilesAndState] <<< 
02:42:30.758 0001 [BookLibForm.OnLoad] <<< 
02:42:32.788 0001 [AudibleApi.GetLibraryAsync] >>> 
02:42:33.727 0001 [Serialization<LibraryResponse>.Deserialize] JsonException: "The JSON value could not be converted to System.Single. Path: $.items[0].percent_complete | LineNumber: 0 | BytePositionInLine: 9919."
02:42:33.727 0001 [BookLibrary.AddRemBooksAsync] >>> #items=0, resync=True
02:42:33.748 0011 [BookLibrary.removeBooks] >>> #items=0
02:42:33.748 0011 [BookLibrary.removeBooks] <<< #items=0
02:42:33.751 0001 [BookLibrary.AddRemBooksAsync] <<< #items=0, resync=True
02:42:33.751 0001 [AudibleApi.GetLibraryAsync] <<< 
02:42:33.751 0001 [AudibleApi.DownloadCoverImagesAsync] >>> 
02:42:33.751 0001 [BookLibrary.AddCoverImagesAsync] >>> 
02:42:33.753 0001 [BookLibrary.AddCoverImagesAsync] #img=0
02:42:33.753 0001 [BookLibrary.AddCoverImagesAsync] <<< 
02:42:33.753 0001 [AudibleApi.DownloadCoverImagesAsync] <<< 
02:42:33.753 0011 [BookLibrary.GetBooks] >>> ProfileId { AccountId = 1, Region = de }
02:42:33.756 0011 [BookLibrary.GetBooks] from DB, #books=0
02:42:33.756 0011 [BookLibrary.GetBooks] <<< ProfileId { AccountId = 1, Region = de }
02:42:33.756 0001 [BookLibDGVControl.setDataSource] #books=0 (deliv type filtered)
02:42:33.756 0001 [BookLibDGVControl.resetDataSource] #books=0 (filtered)
02:44:33.315 0001 [MainForm.OnClosing] >>> 
02:44:33.316 0001 [MainForm.OnClosing] <<< 
denwa777 commented 2 years ago

I have lost sync on my PC as well. I hope I can be of some help.

Log excerpts

13:08:34.976 0001 [AudibleClient.ConfigFromFileAsync] Account 1; jp 13:08:34.976 0001 [BookLibrary.GetAccountAliases] >>> 13:08:35.609 0001 [BookLibrary.GetAccountAliases] #contexts=1 13:08:35.609 0001 [BookLibrary.GetAccountAliases] <<< 13:08:35.610 0001 [Authorize.RefreshTokenAsync] >>> auto=False, onAutoRefeshOnly=True 13:08:35.614 0001 [Authorize.readConfigurationAsync] >>> 13:08:35.614 0001 [Authorize.readConfigurationAsync] <<< 13:08:35.614 0001 [Authorize.RefreshTokenAsync] <<< auto=False, onAutoRefeshOnly=True 13:08:35.614 0001 [BookLibrary.GetAccountId] >>> 13:08:35.667 0001 [BookLibrary.GetAccountId] <<< 13:08:35.730 0001 [MainForm.initLibraryAsync] >>> settings: auto refresh=False, auto update=True 13:08:35.732 0001 [AudibleApi.GetLibraryAsync] >>> 13:08:35.732 0001 [BookLibrary.GetAccountId] >>> 13:08:35.746 0001 [BookLibrary.GetAccountId] <<< 13:08:38.462 0001 [Serialization.Deserialize] JsonException: "The JSON value could not be converted to System.Single. Path: $.items[0].percent_complete | LineNumber: 0 | BytePositionInLine: 4968." 13:08:38.462 0001 [BookLibrary.AddRemBooksAsync] >>> #items=0, resync=False 13:08:38.933 0001 [BookLibrary.AddRemBooksAsync] <<< #items=0, resync=False 13:08:38.934 0001 [AudibleApi.GetLibraryAsync] <<< 13:08:38.935 0001 [AudibleApi.DownloadCoverImagesAsync] >>> 13:08:38.936 0001 [BookLibrary.AddCoverImagesAsync] >>> 13:08:39.200 0001 [BookLibrary.AddCoverImagesAsync] #img=0 13:08:39.270 0001 [BookLibrary.AddCoverImagesAsync] <<< 13:08:39.271 0001 [AudibleApi.DownloadCoverImagesAsync] <<< 13:08:39.272 0001 [MainForm.initLibraryAsync] <<< settings: auto refresh=False, auto update=True 13:08:39.272 0001 [MainForm.init] <<< 13:08:39.364 0001 [MainForm.OnShown] <<< 13:09:08.973 0001 [ConvertDGVControl.btnDnload_Click] 13:09:09.245 0001 [BookLibForm..ctor] Account 1, jp

audiamus commented 2 years ago

Seems that the library reply is empty. I will investigate. But it will take a couple of days, a few other high-prio tasks are on the agenda.

jschoen42 commented 2 years ago

same here, the audiobook i bought today didn't show up in the download list - after that i did a "resynch" several times and every time other audiobooks show up as selectable

try 1: about 50% are not selectable try 2: about 90% are not selectable try 3: about 75% are not selectable

audible (each time the entries have different states)

but the new purchase from 2022-07-03 never shows up (sorted by "purchase date") audible-2

Jürgen

jschoen42 commented 2 years ago

in all logfiles since 2022-07-02 there is an error message

JsonException: "The JSON value could not be converted to System.Single. Path: $.items[0].percent_complete | LineNumber: 0 | BytePositionInLine: xxxx."

extract from 17 log files \audiamus\BookLibConnect\log\BookLibConnect_2022-07-02_001.log(58): 21:21:30.840 0001 [Serialization.Deserialize] JsonException: "The JSON value could not be converted to System.Single. Path: $.items[0].percent_complete | LineNumber: 0 | BytePositionInLine: 4119." \audiamus\BookLibConnect\log\BookLibConnect_2022-07-02_002.log(57): 21:28:18.852 0001 [Serialization.Deserialize] JsonException: "The JSON value could not be converted to System.Single. Path: $.items[0].percent_complete | LineNumber: 0 | BytePositionInLine: 10967." \audiamus\BookLibConnect\log\BookLibConnect_2022-07-03_001.log(58): 19:00:32.672 0001 [Serialization.Deserialize] JsonException: "The JSON value could not be converted to System.Single. Path: $.items[0].percent_complete | LineNumber: 0 | BytePositionInLine: 7707." \audiamus\BookLibConnect\log\BookLibConnect_2022-07-03_002.log(57): 19:03:04.889 0001 [Serialization.Deserialize] JsonException: "The JSON value could not be converted to System.Single. Path: $.items[0].percent_complete | LineNumber: 0 | BytePositionInLine: 7706." \audiamus\BookLibConnect\log\BookLibConnect_2022-07-03_002.log(2092): 19:04:24.798 0001 [Serialization.Deserialize] JsonException: "The JSON value could not be converted to System.Single. Path: $.items[0].percent_complete | LineNumber: 0 | BytePositionInLine: 7706." \audiamus\BookLibConnect\log\BookLibConnect_2022-07-03_002.log(5110): 19:05:41.145 0001 [Serialization.Deserialize] JsonException: "The JSON value could not be converted to System.Single. Path: $.items[0].percent_complete | LineNumber: 0 | BytePositionInLine: 7706." \audiamus\BookLibConnect\log\BookLibConnect_2022-07-03_003.log(57): 19:05:51.015 0001 [Serialization.Deserialize] JsonException: "The JSON value could not be converted to System.Single. Path: $.items[0].percent_complete | LineNumber: 0 | BytePositionInLine: 7706." \audiamus\BookLibConnect\log\BookLibConnect_2022-07-03_003.log(1380): 19:07:31.458 0001 [Serialization.Deserialize] JsonException: "The JSON value could not be converted to System.Single. Path: $.items[0].percent_complete | LineNumber: 0 | BytePositionInLine: 7706." \audiamus\BookLibConnect\log\BookLibConnect_2022-07-03_004.log(57): 19:07:49.913 0001 [Serialization.Deserialize] JsonException: "The JSON value could not be converted to System.Single. Path: $.items[0].percent_complete | LineNumber: 0 | BytePositionInLine: 7706." \audiamus\BookLibConnect\log\BookLibConnect_2022-07-03_005.log(57): 19:14:46.865 0001 [Serialization.Deserialize] JsonException: "The JSON value could not be converted to System.Single. Path: $.items[0].percent_complete | LineNumber: 0 | BytePositionInLine: 7706." \audiamus\BookLibConnect\log\BookLibConnect_2022-07-03_005.log(2671): 19:16:09.618 0001 [Serialization.Deserialize] JsonException: "The JSON value could not be converted to System.Single. Path: $.items[0].percent_complete | LineNumber: 0 | BytePositionInLine: 7706." \audiamus\BookLibConnect\log\BookLibConnect_2022-07-03_006.log(57): 19:16:20.415 0001 [Serialization.Deserialize] JsonException: "The JSON value could not be converted to System.Single. Path: $.items[0].percent_complete | LineNumber: 0 | BytePositionInLine: 7706." \audiamus\BookLibConnect\log\BookLibConnect_2022-07-03_006.log(187): 19:35:10.503 0001 [Serialization.Deserialize] JsonException: "The JSON value could not be converted to System.Single. Path: $.items[0].percent_complete | LineNumber: 0 | BytePositionInLine: 7706." \audiamus\BookLibConnect\log\BookLibConnect_2022-07-03_007.log(57): 19:49:21.099 0001 [Serialization.Deserialize] JsonException: "The JSON value could not be converted to System.Single. Path: $.items[0].percent_complete | LineNumber: 0 | BytePositionInLine: 7706." \audiamus\BookLibConnect\log\BookLibConnect_2022-07-03_008.log(57): 19:51:54.808 0001 [Serialization.Deserialize] JsonException: "The JSON value could not be converted to System.Single. Path: $.items[0].percent_complete | LineNumber: 0 | BytePositionInLine: 7706." \audiamus\BookLibConnect\log\BookLibConnect_2022-07-03_008.log(85): 19:52:32.315 0001 [Serialization.Deserialize] JsonException: "The JSON value could not be converted to System.Single. Path: $.items[0].percent_complete | LineNumber: 0 | BytePositionInLine: 7706." \audiamus\BookLibConnect\log\BookLibConnect_2022-07-03_009.log(57): 19:52:40.196 0001 [Serialization.Deserialize] JsonException: "The JSON value could not be converted to System.Single. Path: $.items[0].percent_complete | LineNumber: 0 | BytePositionInLine: 7706."

Jürgen

audiamus commented 2 years ago

Thanks for all the input. That JSON deserialize exception could be a clue.

There is also the libraryresponse-xxx.json file in the tmp subfolder. Can somebody have a look at a "percent_complete": entry and confirm it has a decimal point?

My suspicion is that this may be related to the German number format setting (with a comma as the decimal symbol) which should normally be neutralized before reading JSON, and that this for some reason no longer works.

jschoen42 commented 2 years ago

in the tmp folder is no file from july 2022, the last is from 2022_06_28 with "percent_complete": 0.0 (5x 0.0, 1x 0.51)

Jürgen

Teekeks commented 2 years ago

For my fresh install that never successfully synced, I do not have that json file at all in the tmp folder, only the RegistrationResponse one

jschoen42 commented 2 years ago

AudibleApi.cs, Line 109: I would remove "percent_complete" from GROUPS when calling the API

Jürgen

ozsmac commented 2 years ago

Just to add that I've found this issue also, Windows 11 and fairly bland install. I can see the following in my log files:

20:30:56.632 0001 [Serialization.Deserialize] JsonException: "The JSON value could not be converted to System.Single. Path: $.items[0].percent_complete | LineNumber: 0 | BytePositionInLine: 8194."

I also don't have any recent json files in the /tmp subfolder, last one is from the last time I ran the app on 23/6.

Happy to help with additional testing and log capture as required.

audiamus commented 2 years ago

Happy to help with additional testing and log capture as required.

German language settings in your Windows system?

Teekeks commented 2 years ago

Not the one you asked but yes, also german lang settings here

ozsmac commented 2 years ago

German language settings in your Windows system?

@audiamus set to English (Australia).

image
ozsmac commented 2 years ago

PS - Just to confirm how my library looks, pressing Resync doesn't change anything (no updates and no errors).

Obviously this isn't urgent or important, but happy to do my little bit to help if needed.

image
Sailfish commented 2 years ago

Just confirming the same here. Also, While I've purchased a few titles in July, they do not show up in the returned list. It appears that the most recent title listed was June 30, 2022.

audiamus commented 2 years ago

Can those of you who suffer from the problem try a full resync once again?

Strange thing is I could reproduce the problem on one machine the other day, but only once. With another attempt today, all books were restored.

Throdne commented 2 years ago

@audiamus Seems to be working for me.

Teekeks commented 2 years ago

Seems to be working now

audiamus commented 2 years ago

Right. I guess this was an Audible server bug. Nonetheless I will change two things:

  1. percent_complete will become a nullable. All other scalar values have been made nullable already. So, if the HTTP json response does not contain that field, the deserialization will no longer abort.
  2. The library response json file will be written to the tmp folder right after the request is completed. Until now it ist only written after deserialization. And we never get there if deserialization crashes. This explains why you couldn't find the library response file.

I will also look at upgrading to .Net 6, as .Net 5 is out of support now.

ozsmac commented 2 years ago

Just to confirm it is working again for me also :)

Sorry this wasted some of your time @audiamus, silly Audible web services issues!!!!

Sailfish commented 2 years ago

WFM.

fwiw, I had done a resync before and retried, to no avail. After retrying, it now works again and even picked up the titles I purchased since June 30th. Hmm, something screwy on Audible server site, I guess?

Thanks!

Sailfish commented 2 years ago

My Win7 only had Net 5. I was able to find a Microsoft Net 6 download page here: https://dotnet.microsoft.com/en-us/download/dotnet

denwa777 commented 2 years ago

I was also able to confirm that it is working correctly. Thanks to all of you for your support. I am also very grateful to the author!

audiamus commented 2 years ago

I have released Version 0.9 just now. It has improved handling of incomplete Audible API responses. And if the response appears to be invalid, your books will no longer be marked as deleted when calling a full resync.

The app has also been migrated to .Net 6.