mkb79 / audible-cli

A command line interface for audible package. With the cli you can download your Audible books, cover, chapter files.
GNU Affero General Public License v3.0
428 stars 45 forks source link

API times out on upgrading from 0.0.9 #109

Open pmcgaley opened 2 years ago

pmcgaley commented 2 years ago

I've been using 0.0.9 for ages with no issues, but today hit the issue of Extreme no longer working in the API, so I updated to the latest 0.2.0.

Now trying to download times out every time. Fetching the library seems to be fine. Adding -t 0 (or anything else) seems to make no difference.

I reverted to 0.0.9 and manually patched it for the Extreme issue and it worked fine. Then experimentally upgraded to 0.1.0 and the timeout came back, so looks like my issue started with that version. Is there anything I need to do to upgrade?

pmcgaley@Pauls-Mac-mini audible % audible download -a B00551W570 --aaxc
No new files downloaded.
Uncaught Exception
Traceback (most recent call last):
  File "/opt/homebrew/lib/python3.9/site-packages/httpx/_transports/default.py", line 62, in map_httpcore_exceptions
    yield
  File "/opt/homebrew/lib/python3.9/site-packages/httpx/_transports/default.py", line 276, in handle_async_request
    ) = await self._pool.handle_async_request(
  File "/opt/homebrew/lib/python3.9/site-packages/httpcore/_async/connection_pool.py", line 234, in handle_async_request
    response = await connection.handle_async_request(
  File "/opt/homebrew/lib/python3.9/site-packages/httpcore/_async/connection.py", line 148, in handle_async_request
    return await self.connection.handle_async_request(
  File "/opt/homebrew/lib/python3.9/site-packages/httpcore/_async/http11.py", line 128, in handle_async_request
    ) = await self._receive_response(timeout)
  File "/opt/homebrew/lib/python3.9/site-packages/httpcore/_async/http11.py", line 189, in _receive_response
    event = await self._receive_event(timeout)
  File "/opt/homebrew/lib/python3.9/site-packages/httpcore/_async/http11.py", line 225, in _receive_event
    data = await self.socket.read(self.READ_NUM_BYTES, timeout)
  File "/opt/homebrew/lib/python3.9/site-packages/httpcore/_backends/anyio.py", line 63, in read
    raise ReadTimeout from None
httpcore.ReadTimeout

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/opt/homebrew/lib/python3.9/site-packages/audible/client.py", line 254, in _request
    resp = await self.session.request(method, url, **kwargs)
  File "/opt/homebrew/lib/python3.9/site-packages/httpx/_client.py", line 1483, in request
    response = await self.send(
  File "/opt/homebrew/lib/python3.9/site-packages/httpx/_client.py", line 1571, in send
    response = await self._send_handling_auth(
  File "/opt/homebrew/lib/python3.9/site-packages/httpx/_client.py", line 1599, in _send_handling_auth
    response = await self._send_handling_redirects(
  File "/opt/homebrew/lib/python3.9/site-packages/httpx/_client.py", line 1636, in _send_handling_redirects
    response = await self._send_single_request(request)
  File "/opt/homebrew/lib/python3.9/site-packages/httpx/_client.py", line 1673, in _send_single_request
    response = await transport.handle_async_request(request)
  File "/opt/homebrew/lib/python3.9/site-packages/httpx/_transports/default.py", line 271, in handle_async_request
    (
  File "/opt/homebrew/Cellar/python@3.9/3.9.13_1/Frameworks/Python.framework/Versions/3.9/lib/python3.9/contextlib.py", line 137, in __exit__
    self.gen.throw(typ, value, traceback)
  File "/opt/homebrew/lib/python3.9/site-packages/httpx/_transports/default.py", line 79, in map_httpcore_exceptions
    raise mapped_exc(message) from exc
httpx.ReadTimeout

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/homebrew/lib/python3.9/site-packages/audible_cli/cli.py", line 69, in main
    sys.exit(cli(*args, **kwargs))
  File "/opt/homebrew/lib/python3.9/site-packages/click/core.py", line 1128, in __call__
    return self.main(*args, **kwargs)
  File "/opt/homebrew/lib/python3.9/site-packages/click/core.py", line 1053, in main
    rv = self.invoke(ctx)
  File "/opt/homebrew/lib/python3.9/site-packages/click/core.py", line 1659, in invoke
    return _process_result(sub_ctx.command.invoke(sub_ctx))
  File "/opt/homebrew/lib/python3.9/site-packages/click/core.py", line 1395, in invoke
    return ctx.invoke(self.callback, **ctx.params)
  File "/opt/homebrew/lib/python3.9/site-packages/click/core.py", line 754, in invoke
    return __callback(*args, **kwargs)
  File "/opt/homebrew/lib/python3.9/site-packages/click/decorators.py", line 84, in new_func
    return ctx.invoke(f, obj, *args, **kwargs)
  File "/opt/homebrew/lib/python3.9/site-packages/click/core.py", line 754, in invoke
    return __callback(*args, **kwargs)
  File "/opt/homebrew/lib/python3.9/site-packages/audible_cli/cmds/cmd_download.py", line 701, in cli
    loop.run_until_complete(main(config, auth, **params))
  File "/opt/homebrew/Cellar/python@3.9/3.9.13_1/Frameworks/Python.framework/Versions/3.9/lib/python3.9/asyncio/base_events.py", line 647, in run_until_complete
    return future.result()
  File "/opt/homebrew/lib/python3.9/site-packages/audible_cli/cmds/cmd_download.py", line 470, in main
    library = await Library.from_api_full_sync(
  File "/opt/homebrew/lib/python3.9/site-packages/audible_cli/models.py", line 351, in from_api_full_sync
    resp = await cls.from_api(api_client, params=request_params)
  File "/opt/homebrew/lib/python3.9/site-packages/audible_cli/models.py", line 336, in from_api
    resp = await api_client.get("library", **request_params)
  File "/opt/homebrew/lib/python3.9/site-packages/audible/client.py", line 273, in _request
    raise NotResponding
audible.exceptions.NotResponding: API request timed out, please be patient.
pmcgaley@Pauls-Mac-mini audible % python3 -m pip list
Package            Version
------------------ ---------
aiofiles           0.8.0
anyio              3.4.0
audible            0.7.2
audible-cli        0.1.0
beautifulsoup4     4.10.0
certifi            2021.10.8
charset-normalizer 2.0.7
click              8.0.3
colorama           0.4.4
h11                0.12.0
httpcore           0.13.7
httpx              0.20.0
idna               3.3
packaging          21.3
pbkdf2             1.3
Pillow             9.0.0
pip                22.1.1
prompt-toolkit     3.0.30
pyaes              1.6.1
pyasn1             0.4.8
PyCocoa            21.8.18
pylivestream       1.11.4
pyparsing          3.0.9
python-vlc         3.0.12118
questionary        1.10.0
requests           2.26.0
requests-toolbelt  0.9.1
rfc3986            1.5.0
rsa                4.8
setuptools         62.3.2
simple-http-server 0.14.10
sniffio            1.2.0
soupsieve          2.3.1
tabulate           0.8.9
termcolor          1.1.0
toml               0.10.2
tqdm               4.62.3
urllib3            1.26.7
wcwidth            0.2.5
wheel              0.37.1
pmcgaley commented 2 years ago

and back to 0.2.0...

Package            Version
------------------ ---------
aiofiles           0.8.0
anyio              3.4.0
audible            0.8.2
audible-cli        0.2.0
beautifulsoup4     4.10.0
certifi            2021.10.8
charset-normalizer 2.0.7
click              8.0.3
colorama           0.4.4
h11                0.12.0
httpcore           0.13.7
httpx              0.20.0
idna               3.3
packaging          21.3
pbkdf2             1.3
Pillow             9.0.0
pip                22.1.1
prompt-toolkit     3.0.30
pyaes              1.6.1
pyasn1             0.4.8
PyCocoa            21.8.18
pylivestream       1.11.4
pyparsing          3.0.9
python-vlc         3.0.12118
questionary        1.10.0
requests           2.26.0
requests-toolbelt  0.9.1
rfc3986            1.5.0
rsa                4.8
setuptools         62.3.2
simple-http-server 0.14.10
sniffio            1.2.0
soupsieve          2.3.1
tabulate           0.8.9
termcolor          1.1.0
toml               0.10.2
tqdm               4.62.3
urllib3            1.26.7
wcwidth            0.2.5
wheel              0.37.1
pmcgaley@Pauls-Mac-mini audible % audible download -t 0 -a B00551W570 --aaxc
Uncaught Exception
Traceback (most recent call last):
  File "/opt/homebrew/lib/python3.9/site-packages/httpx/_transports/default.py", line 62, in map_httpcore_exceptions
    yield
  File "/opt/homebrew/lib/python3.9/site-packages/httpx/_transports/default.py", line 276, in handle_async_request
    ) = await self._pool.handle_async_request(
  File "/opt/homebrew/lib/python3.9/site-packages/httpcore/_async/connection_pool.py", line 234, in handle_async_request
    response = await connection.handle_async_request(
  File "/opt/homebrew/lib/python3.9/site-packages/httpcore/_async/connection.py", line 148, in handle_async_request
    return await self.connection.handle_async_request(
  File "/opt/homebrew/lib/python3.9/site-packages/httpcore/_async/http11.py", line 128, in handle_async_request
    ) = await self._receive_response(timeout)
  File "/opt/homebrew/lib/python3.9/site-packages/httpcore/_async/http11.py", line 189, in _receive_response
    event = await self._receive_event(timeout)
  File "/opt/homebrew/lib/python3.9/site-packages/httpcore/_async/http11.py", line 225, in _receive_event
    data = await self.socket.read(self.READ_NUM_BYTES, timeout)
  File "/opt/homebrew/lib/python3.9/site-packages/httpcore/_backends/anyio.py", line 63, in read
    raise ReadTimeout from None
httpcore.ReadTimeout

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/opt/homebrew/lib/python3.9/site-packages/audible/client.py", line 337, in _request
    resp = await self.session.request(method, url, **kwargs)
  File "/opt/homebrew/lib/python3.9/site-packages/httpx/_client.py", line 1483, in request
    response = await self.send(
  File "/opt/homebrew/lib/python3.9/site-packages/httpx/_client.py", line 1571, in send
    response = await self._send_handling_auth(
  File "/opt/homebrew/lib/python3.9/site-packages/httpx/_client.py", line 1599, in _send_handling_auth
    response = await self._send_handling_redirects(
  File "/opt/homebrew/lib/python3.9/site-packages/httpx/_client.py", line 1636, in _send_handling_redirects
    response = await self._send_single_request(request)
  File "/opt/homebrew/lib/python3.9/site-packages/httpx/_client.py", line 1673, in _send_single_request
    response = await transport.handle_async_request(request)
  File "/opt/homebrew/lib/python3.9/site-packages/httpx/_transports/default.py", line 271, in handle_async_request
    (
  File "/opt/homebrew/Cellar/python@3.9/3.9.13_1/Frameworks/Python.framework/Versions/3.9/lib/python3.9/contextlib.py", line 137, in __exit__
    self.gen.throw(typ, value, traceback)
  File "/opt/homebrew/lib/python3.9/site-packages/httpx/_transports/default.py", line 79, in map_httpcore_exceptions
    raise mapped_exc(message) from exc
httpx.ReadTimeout

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/homebrew/lib/python3.9/site-packages/audible_cli/cli.py", line 60, in main
    sys.exit(cli(*args, **kwargs))
  File "/opt/homebrew/lib/python3.9/site-packages/click/core.py", line 1128, in __call__
    return self.main(*args, **kwargs)
  File "/opt/homebrew/lib/python3.9/site-packages/click/core.py", line 1053, in main
    rv = self.invoke(ctx)
  File "/opt/homebrew/lib/python3.9/site-packages/click/core.py", line 1659, in invoke
    return _process_result(sub_ctx.command.invoke(sub_ctx))
  File "/opt/homebrew/lib/python3.9/site-packages/click/core.py", line 1395, in invoke
    return ctx.invoke(self.callback, **ctx.params)
  File "/opt/homebrew/lib/python3.9/site-packages/click/core.py", line 754, in invoke
    return __callback(*args, **kwargs)
  File "/opt/homebrew/lib/python3.9/site-packages/click/decorators.py", line 84, in new_func
    return ctx.invoke(f, obj, *args, **kwargs)
  File "/opt/homebrew/lib/python3.9/site-packages/click/core.py", line 754, in invoke
    return __callback(*args, **kwargs)
  File "/opt/homebrew/lib/python3.9/site-packages/click/decorators.py", line 84, in new_func
    return ctx.invoke(f, obj, *args, **kwargs)
  File "/opt/homebrew/lib/python3.9/site-packages/click/core.py", line 754, in invoke
    return __callback(*args, **kwargs)
  File "/opt/homebrew/lib/python3.9/site-packages/audible_cli/decorators.py", line 24, in wrapper
    return asyncio.run(f(*args, ** kwargs))
  File "/opt/homebrew/Cellar/python@3.9/3.9.13_1/Frameworks/Python.framework/Versions/3.9/lib/python3.9/asyncio/runners.py", line 44, in run
    return loop.run_until_complete(main)
  File "/opt/homebrew/Cellar/python@3.9/3.9.13_1/Frameworks/Python.framework/Versions/3.9/lib/python3.9/asyncio/base_events.py", line 647, in run_until_complete
    return future.result()
  File "/opt/homebrew/lib/python3.9/site-packages/audible_cli/decorators.py", line 62, in wrapper
    return await f(*args, client, **kwargs)
  File "/opt/homebrew/lib/python3.9/site-packages/audible_cli/cmds/cmd_download.py", line 621, in cli
    library = await Library.from_api_full_sync(
  File "/opt/homebrew/lib/python3.9/site-packages/audible_cli/models.py", line 437, in from_api_full_sync
    library, total_count = await cls.from_api(
  File "/opt/homebrew/lib/python3.9/site-packages/audible_cli/models.py", line 414, in from_api
    resp: httpx.Response = await api_client.get(
  File "/opt/homebrew/lib/python3.9/site-packages/audible/client.py", line 354, in _request
    raise NotResponding
audible.exceptions.NotResponding: API request timed out, please be patient.
mkb79 commented 2 years ago

My first thought is: Please update httpx to v0.23.*! This should solve the issue.

pmcgaley commented 2 years ago

Thanks for the suggestion - unfortunately, no change. Updated everything else outdated for good measure, still no change.

File "/opt/homebrew/lib/python3.9/site-packages/audible/client.py", line 354, in _request
    raise NotResponding
audible.exceptions.NotResponding: API request timed out, please be patient.

pmcgaley@Pauls-Mac-mini audible % python3 -m pip list
Package            Version
------------------ -----------
aiofiles           0.8.0
anyio              3.6.1
audible            0.8.2
audible-cli        0.2.0
beautifulsoup4     4.11.1
certifi            2022.6.15
charset-normalizer 2.1.0
click              8.1.3
colorama           0.4.5
h11                0.13.0
httpcore           0.15.0
httpx              0.23.0
idna               3.3
packaging          21.3
pbkdf2             1.3
Pillow             9.2.0
pip                22.1.2
prompt-toolkit     3.0.30
pyaes              1.6.1
pyasn1             0.4.8
PyCocoa            21.11.4
pylivestream       1.11.4
pyparsing          3.0.9
python-vlc         3.0.16120
questionary        1.10.0
requests           2.28.1
requests-toolbelt  0.9.1
rfc3986            2.0.0
rsa                4.9
setuptools         63.2.0
simple-http-server 0.18.3
sniffio            1.2.0
soupsieve          2.3.2.post1
tabulate           0.8.10
termcolor          1.1.0
toml               0.10.2
tqdm               4.64.0
urllib3            1.26.10
wcwidth            0.2.5
wheel              0.37.1
mkb79 commented 2 years ago

That's really strange. Do you downloading the files in aax or aaxc format? Can you try to set the timeout to 300 and/or set --jobs 1. Make these a difference?

pmcgaley commented 2 years ago

My fault. The clue was in

Adding -t 0 (or anything else) seems to make no difference.

Of course -t is not the timeout. Setting it with --timeout works. Apologies for the wild goose chase.

pmcgaley commented 2 years ago

(curious that it times out pretty much all the time though, and didn't before. Is the API taking longer? Is the default timeout shorter/new? I have a pretty solid 500Mbps down, so it's not network speed - might be worth upping the default timeout?)

mkb79 commented 2 years ago

Network speed is not everything. It is also due to the server location or latency. You can try to set --bunch-size 200. The default is 1,000.

pmcgaley commented 2 years ago

--bunch_size works around the issue too. I had a dig to see what changed (between 0.9 and now) that would account for the slower API call. It seems to be because now far more (all?) response_groups are requested (the default as none are specified in the call from cmd_download to Library.from_api_full_sync), whereas before it was restricted to product_desc, pdf_url, media, product_attrs, relationships.

This change increased that API response time for my library from 2.5 seconds to ~15 seconds. Do we need all of those response_groups when downloading?

mkb79 commented 2 years ago

This is a list with all known response groups and which values for which keys they are provide:

Always returned keys:

1

Requested response groups: contributors Responsed response groups: contributors Keys in the library:

2

Requested response groups: customer_rights Responsed response groups: customer_rights, origin, library_status Keys in the library:

3

Requested response groups: media Responsed response groups: media Keys in the library:

4

Requested response groups: price Responsed response groups: price Keys in the library:

5

Requested response groups: product_attrs Responsed response groups: product_attrs Keys in the library:

6

Requested response groups: product_desc Responsed response groups: product_desc Keys in the library:

7

Requested response groups: product_extended_attrs Responsed response groups: product_extended_attrs Keys in the library:

8

Requested response groups: product_plan_details Responsed response groups: product_plan_details Keys in the library:

9

Requested response groups: product_plans Responsed response groups: product_plans Keys in the library:

10

Requested response groups: rating Responsed response groups: rating Keys in the library:

11

Requested response groups: sample Responsed response groups: sample Keys in the library:

12

Requested response groups: sku Responsed response groups: sku Keys in the library:

13

Requested response groups: series Responsed response groups: series Keys in the library:

14

Requested response groups: reviews Responsed response groups: reviews Keys in the library:

15

Requested response groups: ws4v Responsed response groups: ws4v Keys in the library:

16

Requested response groups: origin Responsed response groups: origin Keys in the library:

17

Requested response groups: relationships Responsed response groups: relationships Keys in the library:

18

Requested response groups: review_attrs Responsed response groups: Keys in the library:

19

Requested response groups: categories Responsed response groups: categories Keys in the library:

20

Requested response groups: badge_types Responsed response groups: origin, badge_types Keys in the library:

21

Requested response groups: category_ladders Responsed response groups: category_ladders Keys in the library:

22

Requested response groups: claim_code_url Responsed response groups: claim_code_url Keys in the library:

23

Requested response groups: in_wishlist Responsed response groups: in_wishlist Keys in the library:

24

Requested response groups: is_archived Responsed response groups: is_archived Keys in the library:

25

Requested response groups: is_downloaded Responsed response groups: is_downloaded Keys in the library:

26

Requested response groups: is_finished Responsed response groups: is_finished Keys in the library:

27

Requested response groups: is_playable Responsed response groups: customer_product_plans, is_playable, product_plans Keys in the library:

28

Requested response groups: is_removable Responsed response groups: is_removable, origin Keys in the library:

29

Requested response groups: is_returnable Responsed response groups: origin, is_returnable Keys in the library:

30

Requested response groups: is_visible Responsed response groups: is_visible Keys in the library:

31

Requested response groups: listening_status Responsed response groups: listening_status Keys in the library:

32

Requested response groups: order_details Responsed response groups: order_details Keys in the library:

33

Requested response groups: origin_asin Responsed response groups: origin_asin, product_attrs Keys in the library:

34

Requested response groups: pdf_url Responsed response groups: pdf_url Keys in the library:

35

Requested response groups: percent_complete Responsed response groups: origin_asin, product_attrs, percent_complete Keys in the library:

36

Requested response groups: periodicals Responsed response groups: periodicals Keys in the library:

37

Requested response groups: provided_review Responsed response groups: Keys in the library:

38

Requested response groups: product_details Responsed response groups: product_details Keys in the library:

mkb79 commented 2 years ago

So we/I can check, which response groups are really needed.

mkb79 commented 2 years ago

@pmcgaley The timeout issue seams to be httpx related. I switched for testing purposes to aiohttp and I don’t get any timeout issues. Maybe I rewrite Audible to use aiohttp instead of httpx. Or I make a new package.

pmcgaley commented 2 years ago

I commented on https://github.com/mkb79/audible-cli/commit/8adeb17776dc5a8030a1cb55ca0c18f79cf59f49 - I think there's another issue that's stopping it from having any effect. Once I fix that locally, the call comes back a lot quicker and I don't get timeouts any more.

Not familiar enough with httpx vs aiohttp but sounds like it might be something to try, although just increasing the default timeout would probably work too - if the changes to response_groups aren't enough in themselves.

mkb79 commented 2 years ago

I commented on https://github.com/mkb79/audible-cli/commit/8adeb17776dc5a8030a1cb55ca0c18f79cf59f49

Fixed this. Good catch

Not familiar enough with httpx vs aiohttp but sounds like it might be something to try, although just increasing the default timeout would probably work too

I've wrote a response group test script with nested asyncio.gather. Using httpx it gives me a NetworkDown or Timeout exception, no matter timeout is set to None on my iOS device and Linux server. Using aiohttp all is running fine. The problem seams to be the nested gather functions. The inner gather functions don’t complete in time because all connection slots are working for the outer gather functions. And audible-cli make use of nested gather functions already.

In fact, the script tested all 38 known response groups for the library endpoint and check which keys they are provide. For each response group my full library are fetched (~130 items), in addition each item is requested two more times using the library/{asin} endpoint and using the parent_asin param. Total there are 38 (130 2 + 1) = 783 requests.