Open ChristinMilloy opened 1 year ago
OzzieIsaacs
commented
1 year ago Please set the loglevel of calibre-web to debug and enable access log, press the force full sync button and try to sync the kobo again. Please post the output of both logbooks here. There might be some api endpoints which aren't supported and therefore return an invalid result for the kobo reader.
quentindavid
commented
12 months ago Hi, I have the same issue. I will post what you asked :)
quentindavid
commented
12 months ago Hi, there is not a lot of understandable logs. On the e-book:
Sep 16 15:05:19 nickel: ( 12837.114 @ 0x26d1ee0 / sync.debug) pumping with 0 pending commands and 0 active commands Sep 16 15:05:19 nickel: ( 12837.160 @ 0x26d1ee0 / sync.debug) virtual void QueuedSyncCommand::cancel() SyncClient(0x2d14690) SyncNotebookCommand(0xae459190) Sep 16 15:05:19 nickel: ( 12837.161 @ 0x26d1ee0 / sync.debug) virtual void QueuedSyncCommand::cancel() SyncNotebookCommand(0xae459190) NotebookListCommand(0x91bc8ce8) Sep 16 15:05:19 nickel: ( 12837.161 @ 0x26d1ee0 / sync.debug) virtual void QueuedSyncCommand::cancel() NotebookListCommand(0x91bc8ce8) NotebookMetadataListParser(0x9e024668) Sep 16 15:05:19 nickel: ( 12837.161 @ 0x26d1ee0 / sync.debug) =================== SYNC QUEUE [ SyncClient(0x2d14690) ] ==================== Sep 16 15:05:19 nickel: ( 12837.161 @ 0x26d1ee0 / sync.debug) ----- Running ------ Sep 16 15:05:19 nickel: ( 12837.161 @ 0x26d1ee0 / sync.debug) [ SyncNotebookCommand(0xae459190) ] Sep 16 15:05:19 nickel: ( 12837.162 @ 0x26d1ee0 / sync.debug) ----- Running ------ Sep 16 15:05:19 nickel: ( 12837.162 @ 0x26d1ee0 / sync.debug) [ NotebookListCommand(0x91bc8ce8) ] Sep 16 15:05:19 nickel: ( 12837.162 @ 0x26d1ee0 / sync.debug) =================================================== Sep 16 15:05:19 nickel: ( 12837.162 @ 0x26d1ee0 / sync.debug)
Sep 16 15:05:19 nickel: ( 12837.162 @ 0x26d1ee0 / sync.debug) pumping with 0 pending commands and 0 active commands Sep 16 15:05:19 nickel: ( 12837.162 @ 0x26d1ee0 / sync.debug) =================== SYNC QUEUE [ SyncClient(0x2d14690) ] ==================== Sep 16 15:05:19 nickel: ( 12837.162 @ 0x26d1ee0 / sync.debug) =================================================== Sep 16 15:05:19 nickel: ( 12837.163 @ 0x26d1ee0 / sync.debug)
Sep 16 15:05:19 nickel: ( 12837.163 @ 0x26d1ee0 / sync.debug) pumping with 0 pending commands and 0 active commands Sep 16 15:05:19 nickel: ( 12837.163 @ 0x26d1ee0 / sync.debug) finished sync client Sep 16 15:05:19 nickel: ( 12837.163 @ 0x26d1ee0 / sync.debug) =================== SYNC QUEUE [ SyncClient(0x2d14690) ] ==================== Sep 16 15:05:19 nickel: ( 12837.163 @ 0x26d1ee0 / sync.debug) =================================================== Sep 16 15:05:19 nickel: ( 12837.163 @ 0x26d1ee0 / sync.debug)
Sep 16 15:05:19 nickel: ( 12837.163 @ 0x26d1ee0 / sync.debug) pumping with 0 pending commands and 0 active commands Sep 16 15:05:19 nickel: ( 12837.164 @ 0x26d1ee0 / sync.debug) SyncNotebookCommand(0xae459190) finished Sep 16 15:05:21 nickel: ( 12839.422 @ 0x1d66538 / ui.warning) virtual bool QDebugSyncErrorFilter::applyFilter(SyncError&) "WebRequestErr"
On calibre-web:
::ffff:172.18.0.9 - - [2023-09-16 13:07:24] "GET /kobo/10xx1e9cxxeb6d0xx3d0d5a4fxxec67b/v1/initialization HTTP/1.1" 200 9280 0.331870 ::ffff:172.18.0.9 - - [2023-09-16 13:07:24] "GET /kobo/10xx1e9cxxeb6d0xx3d0d5a4fxxec67b/v1/user/profile HTTP/1.1" 307 770 0.006932 ::ffff:172.18.0.9 - - [2023-09-16 13:07:25] "GET /kobo/10xx1e9cxxeb6d0xx3d0d5a4fxxec67b/v1/user/loyalty/benefits HTTP/1.1" 307 797 0.004476 ::ffff:172.18.0.9 - - [2023-09-16 13:07:25] "GET /kobo/10xx1e9cxxeb6d0xx3d0d5a4fxxec67b/v1/deals HTTP/1.1" 307 749 0.005355 ::ffff:172.18.0.9 - - [2023-09-16 13:07:25] "GET /kobo/10xx1e9cxxeb6d0xx3d0d5a4fxxec67b/v1/assets?DiffRequests=[%7BKey:EPD-KoboPlus-ReadOnly-NeverSubscribed,ETag:%7D] HTTP/1.1" 404 1626 0.005870 ::ffff:172.18.0.9 - - [2023-09-16 13:07:25] "POST /kobo/10xx1e9cxxeb6d0xx3d0d5a4fxxec67b/v1/analytics/gettests HTTP/1.1" 200 1464 0.320654 ::ffff:172.18.0.9 - - [2023-09-16 13:07:26] "GET /kobo/10xx1e9cxxeb6d0xx3d0d5a4fxxec67b/v1/library/sync?Filter=ALL&DownloadUrlFilter=Generic,Android&PrioritizeRecentReads=true HTTP/1.1" 200 4347 0.429123 ::ffff:172.18.0.9 - - [2023-09-16 13:07:26] "GET /kobo/10xx1e9cxxeb6d0xx3d0d5a4fxxec67b/v1/user/wishlist?PageSize=100&PageIndex=0 HTTP/1.1" 307 856 0.005035
OzzieIsaacs
commented
10 months ago I had time to look into this. Please update to the newest nightly commit. maybe it's working now. The route ".../v1/assets" does no return something. This was maybe confusing the kobo reader
quentindavid
commented
10 months ago Hi @OzzieIsaacs , thanks for the commit ! I updated to newest nightly, and tried to synchronize with notebooks, but I still have an error. Here are the logs from Calibre:
[2023-11-13 10:53:02,042] DEBUG {cps.ub:84} Found stored session: 369ebb552650a46f16256c00d1b858ddxxxxxxxxd6a4acb1d85c3945e58780165f7e6c90446xxxxxxxxxxxxxx56bb9235ad5e4d080299baa7d4xxxxxxxxxe876 [2023-11-13 10:53:02,042] INFO {cps.kobo:1043} Init [2023-11-13 10:53:02,367] DEBUG {cps.kobo:105} Content: b'{"ResponseStatus":{"ErrorCode":"ExpiredToken","Message":"Expired token"}}' [2023-11-13 10:53:02,367] DEBUG {cps.kobo:106} StatusCode: 401 [2023-11-13 10:53:02,514] DEBUG {cps.kobo:964} Unimplemented User Request received: https://[webserver]/kobo/10751e9c78exxxxxxxxxxxxxxc7ec67b/v1/user/profile (request is forwarded to kobo if configured) [2023-11-13 10:53:03,334] DEBUG {cps.kobo:1004} Unimplemented Products Request received: https://[webserver]/kobo/10751e9c78exxxxxxxxxxxxxxc7ec67b/v1/deals (request is forwarded to kobo if configured) [2023-11-13 10:53:03,741] DEBUG {cps.kobo:964} Unimplemented User Request received: https://[webserver]/kobo/10751e9c78exxxxxxxxxxxxxxc7ec67b/v1/assets (request is forwarded to kobo if configured) [2023-11-13 10:53:04,500] DEBUG {cps.kobo:105} Content: b'{"Result":"Success","TestKey":"797xxx71-c1xc-48cx-8368-207xxx8d4565","Tests":{}}' [2023-11-13 10:53:04,500] DEBUG {cps.kobo:106} StatusCode: 200 [2023-11-13 10:53:04,605] DEBUG {cps.ub:84} Found stored session: 369ebb552650a46f1sssssa7d4bce56ea7e876 [2023-11-13 10:53:04,612] INFO {cps.kobo:143} Kobo library sync request received. [2023-11-13 10:53:04,612] DEBUG {cps.kobo:144} SyncToken: 2023-11-13 06:01:54.112508,2023-11-13 06:01:54.199605,0001-01-01 00:00:00,2023-11-13 10:35:46.349014,2023-10-11 13:33:30.998538,eyJ0eXAxxx [2023-11-13 10:53:04,612] DEBUG {cps.kobo:145} Download link format https://[webserver]/kobo/10751e9c78exxxxxxxxxxxxxxc7ec67b/download/%5Bbookid%5D/%5Bbookformat%5D [2023-11-13 10:53:04,626] DEBUG {cps.kobo:204} Books to Sync: 0 [2023-11-13 10:53:04,640] DEBUG {cps.kobo:258} Remaining books to Sync: 0 [2023-11-13 10:53:05,016] DEBUG {cps.kobo:105} Content: b'[]' [2023-11-13 10:53:05,016] DEBUG {cps.kobo:106} StatusCode: 200 [2023-11-13 10:53:05,270] DEBUG {cps.kobo:964} Unimplemented User Request received: https://[webserver]/kobo/10751e9c78exxxxxxxxxxxxxxc7ec67b/v1/user/wishlist (request is forwarded to kobo if configured)
Access logs:
::ffff:172.18.0.3 - - [2023-11-13 10:53:02] "GET /kobo/10751e9c7xxxxxxxxxxxxxxxxxc7ec67b/v1/initialization HTTP/1.1" 200 9283 0.337842 ::ffff:172.18.0.3 - - [2023-11-13 10:53:02] "GET /kobo/10751e9c7xxxxxxxxxxxxxxxxxc7ec67b/v1/user/profile HTTP/1.1" 307 751 0.004222 ::ffff:172.18.0.3 - - [2023-11-13 10:53:02] "GET /kobo/10751e9c7xxxxxxxxxxxxxxxxxc7ec67b/v1/user/loyalty/benefits HTTP/1.1" 307 778 0.002983 ::ffff:172.18.0.3 - - [2023-11-13 10:53:03] "GET /kobo/10751e9c7xxxxxxxxxxxxxxxxxc7ec67b/v1/deals HTTP/1.1" 307 730 0.004230 ::ffff:172.18.0.3 - - [2023-11-13 10:53:03] "GET /kobo/10751e9c7xxxxxxxxxxxxxxxxxc7ec67b/v1/assets?DiffRequests=[%7BKey:EPD-KoboPlus-ReadOnly-NeverSubscribed,ETag:W/NjM4Mss5NzgwMDAwMDAwLTgwNjQ%3D%7D] HTTP/1.1" 307 1048 0.003958 ::ffff:172.18.0.3 - - [2023-11-13 10:53:04] "POST /kobo/10751e9c7xxxxxxxxxxxxxxxxxc7ec67b/v1/analytics/gettests HTTP/1.1" 200 1464 0.374033 ::ffff:172.18.0.3 - - [2023-11-13 10:53:05] "GET /kobo/10751e9c7xxxxxxxxxxxxxxxxxc7ec67b/v1/library/sync?Filter=ALL&DownloadUrlFilter=Generic,Android&PrioritizeRecentReads=true HTTP/1.1" 200 4815 0.420073 ::ffff:172.18.0.3 - - [2023-11-13 10:53:05] "GET /admin/logfile HTTP/1.1" 200 11512 0.014326 ::ffff:172.18.0.3 - - [2023-11-13 10:53:05] "GET /static/css/libs/bootstrap.min.css HTTP/1.1" 304 483 0.003900 ::ffff:172.18.0.3 - - [2023-11-13 10:53:05] "GET /static/css/upload.css HTTP/1.1" 304 474 0.004076 ::ffff:172.18.0.3 - - [2023-11-13 10:53:05] "GET /static/css/style.css HTTP/1.1" 304 474 0.004431 ::ffff:172.18.0.3 - - [2023-11-13 10:53:05] "GET /static/js/libs/jquery.min.js HTTP/1.1" 304 479 0.004455 ::ffff:172.18.0.3 - - [2023-11-13 10:53:05] "GET /static/js/libs/bootstrap.min.js HTTP/1.1" 304 482 0.005331 ::ffff:172.18.0.3 - - [2023-11-13 10:53:05] "GET /static/js/logviewer.js HTTP/1.1" 304 477 0.002964 ::ffff:172.18.0.3 - - [2023-11-13 10:53:05] "GET /static/js/libs/plugins.js HTTP/1.1" 304 476 0.002849 ::ffff:172.18.0.3 - - [2023-11-13 10:53:05] "GET /static/js/main.js HTTP/1.1" 304 472 0.003448 ::ffff:172.18.0.3 - - [2023-11-13 10:53:05] "GET /static/js/libs/jquery.form.min.js HTTP/1.1" 304 483 0.004808 ::ffff:172.18.0.3 - - [2023-11-13 10:53:05] "GET /static/js/uploadprogress.js HTTP/1.1" 304 482 0.004472 ::ffff:172.18.0.3 - - [2023-11-13 10:53:05] "GET /static/js/libs/context.min.js HTTP/1.1" 304 479 0.004827 ::ffff:172.18.0.3 - - [2023-11-13 10:53:05] "GET /static/js/libs/intention.min.js HTTP/1.1" 304 481 0.006442 ::ffff:172.18.0.3 - - [2023-11-13 10:53:05] "GET /static/js/libs/underscore-umd-min.js HTTP/1.1" 304 487 0.004741 ::ffff:172.18.0.3 - - [2023-11-13 10:53:05] "GET /kobo/10751e9c7xxxxxxxxxxxxxxxxxc7ec67b/v1/user/wishlist?PageSize=100&PageIndex=0 HTTP/1.1" 307 837 0.003857 ::ffff:172.18.0.3 - - [2023-11-13 10:53:05] "GET /ajax/log/0?=1699872785178 HTTP/1.1" 200 50247 0.005069 ::ffff:172.18.0.3 - - [2023-11-13 10:53:05] "GET /static/favicon.ico HTTP/1.1" 304 476 0.004400 ::ffff:172.18.0.3 - - [2023-11-13 10:53:25] "GET /ajax/log/1?=1699872785179 HTTP/1.1" 200 37003 0.008227 ::ffff:172.18.0.3 - - [2023-11-13 10:53:42] "GET /ajax/log/0?_=1699872785180 HTTP/1.1" 200 50247 0.006440
peter9teufel
commented
8 months ago Hi @OzzieIsaacs , thanks for the commit ! I updated to newest nightly, and tried to synchronize with notebooks, but I still have an error. Here are the logs from Calibre:
[2023-11-13 10:53:02,042] DEBUG {cps.ub:84} Found stored session: 369ebb552650a46f16256c00d1b858ddxxxxxxxxd6a4acb1d85c3945e58780165f7e6c90446xxxxxxxxxxxxxx56bb9235ad5e4d080299baa7d4xxxxxxxxxe876 [2023-11-13 10:53:02,042] INFO {cps.kobo:1043} Init [2023-11-13 10:53:02,367] DEBUG {cps.kobo:105} Content: b'{"ResponseStatus":{"ErrorCode":"ExpiredToken","Message":"Expired token"}}' [2023-11-13 10:53:02,367] DEBUG {cps.kobo:106} StatusCode: 401 [2023-11-13 10:53:02,514] DEBUG {cps.kobo:964} Unimplemented User Request received: https://[webserver]/kobo/10751e9c78exxxxxxxxxxxxxxc7ec67b/v1/user/profile (request is forwarded to kobo if configured) [2023-11-13 10:53:03,334] DEBUG {cps.kobo:1004} Unimplemented Products Request received: https://[webserver]/kobo/10751e9c78exxxxxxxxxxxxxxc7ec67b/v1/deals (request is forwarded to kobo if configured) [2023-11-13 10:53:03,741] DEBUG {cps.kobo:964} Unimplemented User Request received: https://[webserver]/kobo/10751e9c78exxxxxxxxxxxxxxc7ec67b/v1/assets (request is forwarded to kobo if configured) [2023-11-13 10:53:04,500] DEBUG {cps.kobo:105} Content: b'{"Result":"Success","TestKey":"797xxx71-c1xc-48cx-8368-207xxx8d4565","Tests":{}}' [2023-11-13 10:53:04,500] DEBUG {cps.kobo:106} StatusCode: 200 [2023-11-13 10:53:04,605] DEBUG {cps.ub:84} Found stored session: 369ebb552650a46f1sssssa7d4bce56ea7e876 [2023-11-13 10:53:04,612] INFO {cps.kobo:143} Kobo library sync request received. [2023-11-13 10:53:04,612] DEBUG {cps.kobo:144} SyncToken: 2023-11-13 06:01:54.112508,2023-11-13 06:01:54.199605,0001-01-01 00:00:00,2023-11-13 10:35:46.349014,2023-10-11 13:33:30.998538,eyJ0eXAxxx [2023-11-13 10:53:04,612] DEBUG {cps.kobo:145} Download link format https://[webserver]/kobo/10751e9c78exxxxxxxxxxxxxxc7ec67b/download/%5Bbookid%5D/%5Bbookformat%5D [2023-11-13 10:53:04,626] DEBUG {cps.kobo:204} Books to Sync: 0 [2023-11-13 10:53:04,640] DEBUG {cps.kobo:258} Remaining books to Sync: 0 [2023-11-13 10:53:05,016] DEBUG {cps.kobo:105} Content: b'[]' [2023-11-13 10:53:05,016] DEBUG {cps.kobo:106} StatusCode: 200 [2023-11-13 10:53:05,270] DEBUG {cps.kobo:964} Unimplemented User Request received: https://[webserver]/kobo/10751e9c78exxxxxxxxxxxxxxc7ec67b/v1/user/wishlist (request is forwarded to kobo if configured)
Access logs:
::ffff:172.18.0.3 - - [2023-11-13 10:53:02] "GET /kobo/10751e9c7xxxxxxxxxxxxxxxxxc7ec67b/v1/initialization HTTP/1.1" 200 9283 0.337842 ::ffff:172.18.0.3 - - [2023-11-13 10:53:02] "GET /kobo/10751e9c7xxxxxxxxxxxxxxxxxc7ec67b/v1/user/profile HTTP/1.1" 307 751 0.004222 ::ffff:172.18.0.3 - - [2023-11-13 10:53:02] "GET /kobo/10751e9c7xxxxxxxxxxxxxxxxxc7ec67b/v1/user/loyalty/benefits HTTP/1.1" 307 778 0.002983 ::ffff:172.18.0.3 - - [2023-11-13 10:53:03] "GET /kobo/10751e9c7xxxxxxxxxxxxxxxxxc7ec67b/v1/deals HTTP/1.1" 307 730 0.004230 ::ffff:172.18.0.3 - - [2023-11-13 10:53:03] "GET /kobo/10751e9c7xxxxxxxxxxxxxxxxxc7ec67b/v1/assets?DiffRequests=[%7BKey:EPD-KoboPlus-ReadOnly-NeverSubscribed,ETag:W/NjM4Mss5NzgwMDAwMDAwLTgwNjQ%3D%7D] HTTP/1.1" 307 1048 0.003958 ::ffff:172.18.0.3 - - [2023-11-13 10:53:04] "POST /kobo/10751e9c7xxxxxxxxxxxxxxxxxc7ec67b/v1/analytics/gettests HTTP/1.1" 200 1464 0.374033 ::ffff:172.18.0.3 - - [2023-11-13 10:53:05] "GET /kobo/10751e9c7xxxxxxxxxxxxxxxxxc7ec67b/v1/library/sync?Filter=ALL&DownloadUrlFilter=Generic,Android&PrioritizeRecentReads=true HTTP/1.1" 200 4815 0.420073 ::ffff:172.18.0.3 - - [2023-11-13 10:53:05] "GET /admin/logfile HTTP/1.1" 200 11512 0.014326 ::ffff:172.18.0.3 - - [2023-11-13 10:53:05] "GET /static/css/libs/bootstrap.min.css HTTP/1.1" 304 483 0.003900 ::ffff:172.18.0.3 - - [2023-11-13 10:53:05] "GET /static/css/upload.css HTTP/1.1" 304 474 0.004076 ::ffff:172.18.0.3 - - [2023-11-13 10:53:05] "GET /static/css/style.css HTTP/1.1" 304 474 0.004431 ::ffff:172.18.0.3 - - [2023-11-13 10:53:05] "GET /static/js/libs/jquery.min.js HTTP/1.1" 304 479 0.004455 ::ffff:172.18.0.3 - - [2023-11-13 10:53:05] "GET /static/js/libs/bootstrap.min.js HTTP/1.1" 304 482 0.005331 ::ffff:172.18.0.3 - - [2023-11-13 10:53:05] "GET /static/js/logviewer.js HTTP/1.1" 304 477 0.002964 ::ffff:172.18.0.3 - - [2023-11-13 10:53:05] "GET /static/js/libs/plugins.js HTTP/1.1" 304 476 0.002849 ::ffff:172.18.0.3 - - [2023-11-13 10:53:05] "GET /static/js/main.js HTTP/1.1" 304 472 0.003448 ::ffff:172.18.0.3 - - [2023-11-13 10:53:05] "GET /static/js/libs/jquery.form.min.js HTTP/1.1" 304 483 0.004808 ::ffff:172.18.0.3 - - [2023-11-13 10:53:05] "GET /static/js/uploadprogress.js HTTP/1.1" 304 482 0.004472 ::ffff:172.18.0.3 - - [2023-11-13 10:53:05] "GET /static/js/libs/context.min.js HTTP/1.1" 304 479 0.004827 ::ffff:172.18.0.3 - - [2023-11-13 10:53:05] "GET /static/js/libs/intention.min.js HTTP/1.1" 304 481 0.006442 ::ffff:172.18.0.3 - - [2023-11-13 10:53:05] "GET /static/js/libs/underscore-umd-min.js HTTP/1.1" 304 487 0.004741 ::ffff:172.18.0.3 - - [2023-11-13 10:53:05] "GET /kobo/10751e9c7xxxxxxxxxxxxxxxxxc7ec67b/v1/user/wishlist?PageSize=100&PageIndex=0 HTTP/1.1" 307 837 0.003857 ::ffff:172.18.0.3 - - [2023-11-13 10:53:05] "GET /ajax/log/0?=1699872785178 HTTP/1.1" 200 50247 0.005069 ::ffff:172.18.0.3 - - [2023-11-13 10:53:05] "GET /static/favicon.ico HTTP/1.1" 304 476 0.004400 ::ffff:172.18.0.3 - - [2023-11-13 10:53:25] "GET /ajax/log/1?=1699872785179 HTTP/1.1" 200 37003 0.008227 ::ffff:172.18.0.3 - - [2023-11-13 10:53:42] "GET /ajax/log/0?_=1699872785180 HTTP/1.1" 200 50247 0.006440
This seems to be something else, I am currently struggling with the same issue, as the error states this happens due to the fact that the auth token for the kobo store expires and is not being refreshed. There's a separate issue for this here 2318
It looks like this problem can be resolved by re-setting the api_endpoint to the kobo store URL for one sync, this refreshes token, then set back the api_endpoint. But the problem will be back again after 1 or 2 days in my case, so this is just a workaround and not a real solution.
campbellr
commented
8 months ago I was having the same issue where Init gets an "Expired token" response from the store, which ends up falling back to a generic/hardcoded response (NATIVE_KOBO_RESPONSES()) instead of refreshing the token.
On a whim I made the following change (with the assumption that if we forward the "expired token" response back to the device it might trigger a token refresh flow):
diff --git a/cps/kobo.py b/cps/kobo.py
index 76530797..f56a5652 100644
--- a/cps/kobo.py
+++ b/cps/kobo.py
@@ -1049,6 +1049,15 @@ def HandleInitRequest():
store_response_json = store_response.json()
if "Resources" in store_response_json:
kobo_resources = store_response_json["Resources"]
+ else:
+ # HACK: This should maybe only happen when we get an "expired token" response?
+ # Btw, the below code was copy-pasted from redirect_or_proxy_request()
+ response_headers = store_response.headers
+ for header_key in CONNECTION_SPECIFIC_HEADERS:
+ response_headers.pop(header_key, default=None)
+
+ return make_response(
+ store_response.content, store_response.status_code, response_headers.items()
+ )
except Exception:
log.error("Failed to receive or parse response from Kobo's init endpoint. Falling back to un-proxied mode.")
if not kobo_resources:It seems to have done the trick for me, because the sync succeeded and I see the following in the logs:
[2024-01-14 14:57:10,504] DEBUG {cps.ub:84} Found stored session: 80b3e0f86304a884c6bdb7884b2533f274baca3737403ebafdab81c23cb65810d2344919c4234224dc68649030c342b9d416495dd9dedbb3b88385d67abbd2b3
[2024-01-14 14:57:10,504] INFO {cps.kobo:1043} Init
[2024-01-14 14:57:10,810] DEBUG {cps.kobo:105} Content: b'{"ResponseStatus":{"ErrorCode":"ExpiredToken","Message":"Expired token"}}'
[2024-01-14 14:57:10,811] DEBUG {cps.kobo:106} StatusCode: 401
==> access.log <==
[2024-01-14 14:57:10,813] 401 GET /kobo/xxxx/v1/initialization (192.168.0.18) 314.21ms
[2024-01-14 14:57:10,843] 404 POST /kobo/xxxx/v1/auth/refresh (192.168.0.18) 20.09ms
==> calibre-web.log <==
[2024-01-14 14:57:10,914] DEBUG {cps.ub:84} Found stored session: xxx
[2024-01-14 14:57:10,914] DEBUG {cps.kobo:1031} Kobo Auth request
[2024-01-14 14:57:11,149] DEBUG {cps.kobo:105} Content: b'{"AccessToken":"...","TokenType":"Bearer","RefreshToken":"..."}'
[2024-01-14 14:57:11,150] DEBUG {cps.kobo:106} StatusCode: 200 Note the follow-up "initialization" and "auth/refresh" API calls after we return the "Expired token" response.
Not sure about the 404 on the "auth/refresh" call through, to be honest...
I really don't know anything about how the sync protocol or kobo auth is supposed to work though, but hopefully this is helpful to someone more familiar than me (@OzzieIsaacs perhaps?)
For what it's worth, I also have "proxy unknown requests to Kobo Store" enabled.
campbellr
commented
8 months ago And for what it's worth, the real Resources payload I get back for my device has quite a bit more stuff than the hardcoded NATIVE_KOBO_RESOURCES() does... including a notebooks url, which I assume is important for syncing notebooks:
"notebooks": "https://storeapi.kobo.com/api/internal/notebooks",Had the same idea to pass the "expired token" response to the reader as this is a quite common usecase to trigger the call to a token refresh api. Tried your simple hack now and it works like a charm, thanks a lot!
Best regards, Peter
quentindavid
commented
3 weeks ago Can you describe what you mean by his simple hack ? Modify cps/kobo.py + adding "notebooks" resource ?
I'd like to test on my side too :)
Describe the bug/problem User 1 with Kobo Aura H2O is able to sync perfectly with Calibre-Web (Aura, no notebook feature). However User 2 with pen-enabled Kobo Ellipsa eReader is only able to sync properly if "synchronize notebooks" setting is disabled. When notebook sync is enabled, Sync always fails with "synchronization error." Also (and most critically) her handwritten notebook content is not backed up to kobo.com.
To Reproduce Steps to reproduce the behavior:
Logfile [2023-07-26 12:35:14,493] INFO {cps:176} Starting Calibre Web... [2023-07-26 12:35:15,785] WARN {py.warnings:109} /usr/local/lib/python3.10/dist-packages/flask_limiter/extension.py:293: UserWarning: Using the in-memory storage for tracking rate limits as no storage was explicitly specified. This is not recommended for production use. See: https://flask-limiter.readthedocs.io#configuring-a-storage-backend for documentation about configuring the storage backend. warnings.warn( [2023-07-26 12:35:16,800] INFO {apscheduler.scheduler:171} Scheduler started [2023-07-26 12:35:16,805] INFO {apscheduler.scheduler:885} Added job "end scheduled task" to job store "default"
[2023-07-26 12:35:31,261] INFO {cps.kobo:1066} Init [2023-07-26 12:35:33,536] INFO {cps.kobo:143} Kobo library sync request received. [2023-07-26 12:35:33,563] WARN {py.warnings:109} /app/calibre-web/cps/db.py:549: SAWarning: This declarative base already contains a class with the same class name and module name as cps.db.custom_column_1, and will be replaced in the string-lookup table. cc_classes[row.id] = type(str('customcolumn' + str(row.id)), (Base,), ccdict) [2023-07-26 12:35:33,567] WARN {py.warnings:109} /app/calibre-web/cps/db.py:565: SAWarning: Property Books.custom_column_1 on mapped class Books->books being replaced with new property Books.custom_column_1; the old property will be discarded setattr(Books, [2023-07-26 12:35:33,619] WARN {py.warnings:109} /app/calibre-web/cps/kobo.py:266: SAWarning: SELECT statement has a cartesian product between FROM element(s) "archived_book" and FROM element "anon_1". Apply join condition(s) between each element to resolve. .order_by(func.datetime(ub.ArchivedBook.last_modified).desc()).first() [2023-07-26 12:41:26,938] INFO {cps.kobo:1066} Init [2023-07-26 12:41:28,291] INFO {cps.kobo:143} Kobo library sync request received. [2023-07-26 12:41:28,345] WARN {py.warnings:109} /app/calibre-web/cps/kobo.py:266: SAWarning: SELECT statement has a cartesian product between FROM element(s) "anon_1" and FROM element "archived_book". Apply join condition(s) between each element to resolve. .order_by(func.datetime(ub.ArchivedBook.last_modified).desc()).first() [2023-07-26 12:47:05,975] INFO {cps.kobo:1066} Init [2023-07-26 12:47:07,389] INFO {cps.kobo:143} Kobo library sync request received. [2023-07-26 13:00:32,606] INFO {cps.kobo:1066} Init [2023-07-26 13:00:35,542] INFO {cps.kobo:143} Kobo library sync request received. [2023-07-26 13:01:08,703] INFO {cps.kobo:1066} Init [2023-07-26 13:01:12,827] INFO {cps.kobo:143} Kobo library sync request received. [2023-07-26 13:07:26,256] INFO {cps.kobo:1066} Init [2023-07-26 13:07:29,019] INFO {cps.kobo:786} Book 31adba1e-5686-45dc-b20e-61c362d890ea not found in database [2023-07-26 13:07:30,530] INFO {cps.kobo:143} Kobo library sync request received.
Expected behavior Instead of failure with error message, Sync should give successful result. Ideally, handwritten notebook files should fall through "proxy unknown request to Kobo store" and be backed up in Kobo account (or, backed up in calibre as future feature).
Environment (please complete the following information):
Additional context using http over local lan for api-endpoint (no SSL, no domain, no reverse proxy)