Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Discovery code can trigger TimeoutError on some inverters when using ALL_COMPLETED #150

Closed
brew-your-own opened this issue Apr 23, 2024 · 2 comments · Fixed by #153
Closed

Comments

@brew-your-own
Copy link
Contributor

I am logging this after discussing this with @Darsstar in the context of home-assistant/core#115129

This happens in release 3.1.0 which features new improved discovery code by @Darsstar

Inverter: X1HybridGen4

Here is the code I am using to test:
`
loop = asyncio.new_event_loop()
asyncio.set_event_loop(loop)

inverters = loop.run_until_complete(solax.discover("solax.home.arpa", 80, "XXXXX", return_when=asyncio.ALL_COMPLETED))

if isinstance(inverters, set):
    logging.info("returned set of inverters")
    for inverter in inverters:
        logging.info("found inverter %s", inverter)
        print(loop.run_until_complete(inverter.get_data()))
else:
    logging.info("found inverter %s", inverters)
    print(loop.run_until_complete(inverters.get_data()))

loop.close()

`

This code will, most of the time, result in a TimeoutError:
`
INFO:root:Trying inverter X1Smart::http://solax.home.arpa:80/ using query in url
INFO:root:Trying inverter X1Smart::http://solax.home.arpa:80/ using data in the body
INFO:root:Trying inverter X1HybridGen4::http://solax.home.arpa:80/ using data in the body
INFO:root:Trying inverter QVOLTHYBG33P::http://solax.home.arpa:80/ using data in the body
INFO:root:Trying inverter X1::http://solax.home.arpa:80/ using query in url
INFO:root:Trying inverter X1::http://solax.home.arpa:80/ using data in the body
INFO:root:Trying inverter X3V34::http://solax.home.arpa:80/ using data in the body
INFO:root:Trying inverter X3V34::http://solax.home.arpa:80/ using query in url
INFO:root:Trying inverter X1Mini::http://solax.home.arpa:80/ using query in url
INFO:root:Trying inverter X1Mini::http://solax.home.arpa:80/ using data in the body
INFO:root:Trying inverter X1MiniV34::http://solax.home.arpa:80/ using data in the body
INFO:root:Trying inverter X1MiniV34::http://solax.home.arpa:80/ using query in url
INFO:root:Trying inverter X3::http://solax.home.arpa:80/ using query in url
INFO:root:Trying inverter X3::http://solax.home.arpa:80/ using data in the body
INFO:root:Trying inverter XHybrid::http://solax.home.arpa:80/api/realTimeData.htm using data in the body
INFO:root:Trying inverter X3MicProG2::http://solax.home.arpa:80/ using data in the body
INFO:root:Trying inverter X1Boost::http://solax.home.arpa:80/ using query in url
INFO:root:Trying inverter X1Boost::http://solax.home.arpa:80/ using data in the body
INFO:root:Trying inverter X3HybridG4::http://solax.home.arpa:80/ using data in the body
Traceback (most recent call last):
File "/Users/xxxxx/Documents/projects/solax/.venv/lib/python3.11/site-packages/solax/discovery.py", line 122, in discover
done, pending = await asyncio.wait(pending, return_when=return_when)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/opt/homebrew/Cellar/python@3.11/3.11.9/Frameworks/Python.framework/Versions/3.11/lib/python3.11/asyncio/tasks.py", line 428, in wait
return await _wait(fs, timeout, return_when, loop)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/opt/homebrew/Cellar/python@3.11/3.11.9/Frameworks/Python.framework/Versions/3.11/lib/python3.11/asyncio/tasks.py", line 535, in _wait
await waiter
asyncio.exceptions.CancelledError

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
File "/Users/xxxxx/Documents/projects/solax-simple/solax-simple copy.py", line 29, in
main()
File "/Users/xxxxx/Documents/projects/solax-simple/solax-simple copy.py", line 15, in main
inverters = loop.run_until_complete(solax.discover("solax.home.arpa", 80, "xxxxxx", return_when=asyncio.ALL_COMPLETED))
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/opt/homebrew/Cellar/python@3.11/3.11.9/Frameworks/Python.framework/Versions/3.11/lib/python3.11/asyncio/base_events.py", line 654, in run_until_complete
return future.result()
^^^^^^^^^^^^^^^
File "/Users/xxxxx/Documents/projects/solax/.venv/lib/python3.11/site-packages/solax/discovery.py", line 75, in discover
async with timeout(kwargs.get("timeout", 15)):
File "/Users/xxxxx/Documents/projects/solax/.venv/lib/python3.11/site-packages/async_timeout-4.0.3-py3.11.egg/async_timeout/init.py", line 141, in aexit
self._do_exit(exc_type)
File "/Users/xxxxx/Documents/projects/solax/.venv/lib/python3.11/site-packages/async_timeout-4.0.3-py3.11.egg/async_timeout/init.py", line 228, in _do_exit
raise asyncio.TimeoutError
TimeoutError
`

Using asyncio.FIRST_COMPLETED works:
INFO:root:Trying inverter X1Mini::http://solax.home.arpa:80/ using data in the body INFO:root:Trying inverter X1Mini::http://solax.home.arpa:80/ using query in url INFO:root:Trying inverter X1Smart::http://solax.home.arpa:80/ using query in url INFO:root:Trying inverter X1Smart::http://solax.home.arpa:80/ using data in the body INFO:root:Trying inverter X3MicProG2::http://solax.home.arpa:80/ using data in the body INFO:root:Trying inverter X3::http://solax.home.arpa:80/ using query in url INFO:root:Trying inverter X3::http://solax.home.arpa:80/ using data in the body INFO:root:Trying inverter X1MiniV34::http://solax.home.arpa:80/ using query in url INFO:root:Trying inverter X1MiniV34::http://solax.home.arpa:80/ using data in the body INFO:root:Trying inverter X3HybridG4::http://solax.home.arpa:80/ using data in the body INFO:root:Trying inverter X3V34::http://solax.home.arpa:80/ using query in url INFO:root:Trying inverter X3V34::http://solax.home.arpa:80/ using data in the body INFO:root:Trying inverter XHybrid::http://solax.home.arpa:80/api/realTimeData.htm using data in the body INFO:root:Trying inverter QVOLTHYBG33P::http://solax.home.arpa:80/ using data in the body INFO:root:Trying inverter X1::http://solax.home.arpa:80/ using query in url INFO:root:Trying inverter X1::http://solax.home.arpa:80/ using data in the body INFO:root:Trying inverter X1HybridGen4::http://solax.home.arpa:80/ using data in the body INFO:root:Trying inverter X1Boost::http://solax.home.arpa:80/ using query in url INFO:root:Trying inverter X1Boost::http://solax.home.arpa:80/ using data in the body INFO:root:Discovered inverters: {<solax.inverters.x1_hybrid_gen4.X1HybridGen4 object at 0x106c4b7d0>} INFO:root:found inverter X1HybridGen4::http://solax.home.arpa:80/ using data in the body InverterResponse(data={....})

@Darsstar
Copy link
Contributor

Darsstar commented Apr 24, 2024

Could you test two scenarios?

If both work than a) I understand what is going on and b) we know how to fix it

Currently there are two timeouts:

That branch removes the single timeout for the entire discovery function and replaces it with timeouts for each request via asyncio.wait_for(). Those wait_for calls are scheduled as tasks so they should not cause a TimeoutError to be thrown from discover() and instead be filtered out by remove_failures_from(done).

edit: the branch no longer uses asyncio.wait_for and instead gives the timeout to aiohttp's get and post methods.

@brew-your-own
Copy link
Contributor Author

I should have looked at your code a bit closer, it was all there for me to see. I really appreciate your patience :)

3.1.0 with timeout=360 works. FYI it actually takes approx 304s
with timeout=250, it fails.

with your rework-discovery-timeout branch, it also works but does it in under 10s - much improved!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging a pull request may close this issue.

2 participants