search

davidusb-geek / emhass-add-on

The Home Assistant Add-on for EMHASS: Energy Management Optimization for Home Assistant
MIT License
92 stars 28 forks source link

Timed out running command when passing forecast data #37

Closed overas closed 1 year ago

overas commented 1 year ago

Hassos 2023.2.5 Emhass addon 0.2.29 Home Assistant Yellow

image

I am trying to pass cost and sell electricity prices from Nordpool addon to emhass.

I am using the shell_command from the emhass documentation:

shell_command:
  trigger_nordpool_forecast: "curl -i -H \"Content-Type: application/json\" -X POST -d '{\"load_cost_forecast\":{{((state_attr('sensor.nordpool', 'raw_today') | map(attribute='value') | list  + state_attr('sensor.nordpool', 'raw_tomorrow') | map(attribute='value') | list))[now().hour:][:24] }},\"prod_price_forecast\":{{((state_attr('sensor.nordpool', 'raw_today') | map(attribute='value') | list  + state_attr('sensor.nordpool', 'raw_tomorrow') | map(attribute='value') | list))[now().hour:][:24]}}}' http://localhost:5000/action/dayahead-optim"

which outputs this in the Template editor: image

Emhass gives no error, but the load_cost_forecast and prod_price_forecast are not updated image

s6-rc: info: service s6rc-oneshot-runner: starting
s6-rc: info: service s6rc-oneshot-runner successfully started
s6-rc: info: service fix-attrs: starting
s6-rc: info: service fix-attrs successfully started
s6-rc: info: service legacy-cont-init: starting
s6-rc: info: service legacy-cont-init successfully started
s6-rc: info: service legacy-services: starting
services-up: info: copying legacy longrun emhass (no readiness notification)
s6-rc: info: service legacy-services successfully started
[2023-03-03 16:59:38,141] INFO in web_server: Launching the emhass webserver at: http://0.0.0.0:5000
[2023-03-03 16:59:38,143] INFO in web_server: Home Assistant data fetch will be performed using url: http://supervisor/core/api
[2023-03-03 16:59:38,143] INFO in web_server: The data path is: /share
[2023-03-03 16:59:38,148] INFO in web_server: Using core emhass version: 0.3.36
[2023-03-03 17:00:00,583] INFO in command_line: Setting up needed data
[2023-03-03 17:00:00,700] INFO in web_server:  >> Publishing data...
[2023-03-03 17:00:00,700] INFO in command_line: Publishing data to HASS instance
[2023-03-03 17:00:00,770] INFO in retrieve_hass: Successfully posted to sensor.p_pv_forecast = 60.62
[2023-03-03 17:00:00,807] INFO in retrieve_hass: Successfully posted to sensor.p_load_forecast = 1281.76
[2023-03-03 17:00:00,846] INFO in retrieve_hass: Successfully posted to sensor.p_deferrable0 = 0.0
[2023-03-03 17:00:00,886] INFO in retrieve_hass: Successfully posted to sensor.p_deferrable1 = 0.0
[2023-03-03 17:00:00,922] INFO in retrieve_hass: Successfully posted to sensor.p_deferrable2 = 1450.0
[2023-03-03 17:00:00,961] INFO in retrieve_hass: Successfully posted to sensor.p_deferrable3 = 0.0
[2023-03-03 17:00:00,994] INFO in retrieve_hass: Successfully posted to sensor.p_deferrable4 = 0.0
[2023-03-03 17:00:01,028] INFO in retrieve_hass: Successfully posted to sensor.p_deferrable5 = 0.0
[2023-03-03 17:00:01,061] INFO in retrieve_hass: Successfully posted to sensor.p_deferrable6 = 947.0
[2023-03-03 17:00:01,097] INFO in retrieve_hass: Successfully posted to sensor.p_deferrable7 = 0.0
[2023-03-03 17:00:01,129] INFO in retrieve_hass: Successfully posted to sensor.p_grid_forecast = 3618.14
[2023-03-03 17:00:01,162] INFO in retrieve_hass: Successfully posted to sensor.total_cost_fun_value = -18.05
[2023-03-03 17:00:18,726] INFO in command_line: Setting up needed data
[2023-03-03 17:00:18,731] INFO in forecast: Retrieving weather forecast data using method = scrapper
[2023-03-03 17:00:25,001] INFO in forecast: Retrieving data from hass for load forecast using method = naive
[2023-03-03 17:00:25,009] INFO in retrieve_hass: Retrieve hass get data method initiated...
[2023-03-03 17:00:28,665] INFO in web_server:  >> Performing dayahead optimization...
[2023-03-03 17:00:28,665] INFO in command_line: Performing day-ahead forecast optimization
[2023-03-03 17:00:28,700] INFO in optimization: Perform optimization for the day-ahead
[2023-03-03 17:01:13,395] INFO in web_server: EMHASS server online, serving index.html...
[2023-03-03 17:05:00,661] INFO in command_line: Setting up needed data
[2023-03-03 17:05:00,678] INFO in web_server:  >> Publishing data...
[2023-03-03 17:05:00,679] INFO in command_line: Publishing data to HASS instance
[2023-03-03 17:05:00,791] INFO in retrieve_hass: Successfully posted to sensor.p_pv_forecast = 60.62
[2023-03-03 17:05:00,855] INFO in retrieve_hass: Successfully posted to sensor.p_load_forecast = 1281.76
[2023-03-03 17:05:00,935] INFO in retrieve_hass: Successfully posted to sensor.p_deferrable0 = 0.0
[2023-03-03 17:05:01,002] INFO in retrieve_hass: Successfully posted to sensor.p_deferrable1 = 0.0
[2023-03-03 17:05:01,062] INFO in retrieve_hass: Successfully posted to sensor.p_deferrable2 = 1450.0
[2023-03-03 17:05:01,118] INFO in retrieve_hass: Successfully posted to sensor.p_deferrable3 = 0.0
[2023-03-03 17:05:01,178] INFO in retrieve_hass: Successfully posted to sensor.p_deferrable4 = 0.0
[2023-03-03 17:05:01,230] INFO in retrieve_hass: Successfully posted to sensor.p_deferrable5 = 0.0
[2023-03-03 17:05:01,290] INFO in retrieve_hass: Successfully posted to sensor.p_deferrable6 = 947.0
[2023-03-03 17:05:01,344] INFO in retrieve_hass: Successfully posted to sensor.p_deferrable7 = 0.0
[2023-03-03 17:05:01,399] INFO in retrieve_hass: Successfully posted to sensor.p_grid_forecast = 3618.14
[2023-03-03 17:05:01,450] INFO in retrieve_hass: Successfully posted to sensor.total_cost_fun_value = -18.05
[2023-03-03 17:10:00,622] INFO in command_line: Setting up needed data
[2023-03-03 17:10:00,630] INFO in web_server:  >> Publishing data...

Hassos logs Timed out running command :

Logger: homeassistant.components.shell_command
Source: components/shell_command/__init__.py:83
Integration: Shell Command (documentation, issues)
First occurred: 17:01:18 (1 occurrences)
Last logged: 17:01:18

Timed out running command: `curl -i -H "Content-Type: application/json" -X POST -d '{"load_cost_forecast":{{((state_attr('sensor.nordpool', 'raw_today') | map(attribute='value') | list + state_attr('sensor.nordpool', 'raw_tomorrow') | map(attribute='value') | list))[now().hour:][:24] }},"prod_price_forecast":{{((state_attr('sensor.nordpool', 'raw_today') | map(attribute='value') | list + state_attr('sensor.nordpool', 'raw_tomorrow') | map(attribute='value') | list))[now().hour:][:24]}}}' http://localhost:5000/action/dayahead-optim`, after: 60s
Traceback (most recent call last):
  File "/usr/local/lib/python3.10/asyncio/streams.py", line 502, in _wait_for_data
    await self._waiter
asyncio.exceptions.CancelledError

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.10/asyncio/subprocess.py", line 195, in communicate
    stdin, stdout, stderr = await tasks.gather(stdin, stdout, stderr)
asyncio.exceptions.CancelledError

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.10/asyncio/tasks.py", line 456, in wait_for
    return fut.result()
asyncio.exceptions.CancelledError

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

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/shell_command/__init__.py", line 83, in async_service_handler
    stdout_data, stderr_data = await asyncio.wait_for(
  File "/usr/local/lib/python3.10/asyncio/tasks.py", line 458, in wait_for
    raise exceptions.TimeoutError() from exc
asyncio.exceptions.TimeoutError

Hassos log: home-assistant_2023-03-03T16-07-07.463Z.log

davidusb-geek commented 1 year ago

Ok could you please restart the add-on then don't do any data publish task, then show the complete logs of just running the day-ahead optimization task?

overas commented 1 year ago

I have only Nordpool today prices when doing this test. Running this day-ahead automation:

alias: EMHASS day-ahead optimization
description: ""
trigger:
  - platform: time
    at: "23:10:00"
condition: []
action:
  - service: shell_command.trigger_nordpool_forecast
    data: {}
mode: single

I use this Shell_command:

shell_command:
  publish_data: "curl -i -H 'Content-Type:application/json' -X POST -d '{}' http://localhost:5000/action/publish-data"

  trigger_nordpool_forecast: "curl -i -H \"Content-Type: application/json\" -X POST -d '{\"load_cost_forecast\":{{((state_attr('sensor.nordpool', 'raw_today') | map(attribute='value') | list  + state_attr('sensor.nordpool', 'raw_tomorrow') | map(attribute='value') | list))[now().hour:][:24] }},\"prod_price_forecast\":{{((state_attr('sensor.nordpool', 'raw_today') | map(attribute='value') | list  + state_attr('sensor.nordpool', 'raw_tomorrow') | map(attribute='value') | list))[now().hour:][:24]}}}' http://localhost:5000/action/dayahead-optim"

Emhass is logging:

s6-rc: info: service s6rc-oneshot-runner: starting
s6-rc: info: service s6rc-oneshot-runner successfully started
s6-rc: info: service fix-attrs: starting
s6-rc: info: service fix-attrs successfully started
s6-rc: info: service legacy-cont-init: starting
s6-rc: info: service legacy-cont-init successfully started
s6-rc: info: service legacy-services: starting
services-up: info: copying legacy longrun emhass (no readiness notification)
s6-rc: info: service legacy-services successfully started
[2023-03-04 11:33:32,938] INFO in web_server: Launching the emhass webserver at: http://0.0.0.0:5000
[2023-03-04 11:33:32,939] INFO in web_server: Home Assistant data fetch will be performed using url: http://supervisor/core/api
[2023-03-04 11:33:32,939] INFO in web_server: The data path is: /share
[2023-03-04 11:33:32,944] INFO in web_server: Using core emhass version: 0.3.36
[2023-03-04 11:33:51,192] INFO in command_line: Setting up needed data
[2023-03-04 11:33:51,276] ERROR in utils: ERROR: The passed data is either not a list or the length is not correct, length should be 24
[2023-03-04 11:33:51,276] ERROR in utils: Passed type is <class 'list'> and length is 24
[2023-03-04 11:33:51,277] ERROR in utils: ERROR: The passed data is either not a list or the length is not correct, length should be 24
[2023-03-04 11:33:51,278] ERROR in utils: Passed type is <class 'list'> and length is 24
[2023-03-04 11:33:51,283] INFO in forecast: Retrieving weather forecast data using method = scrapper
[2023-03-04 11:33:56,062] INFO in forecast: Retrieving data from hass for load forecast using method = naive
[2023-03-04 11:33:56,065] INFO in retrieve_hass: Retrieve hass get data method initiated...
[2023-03-04 11:34:00,636] INFO in web_server:  >> Performing dayahead optimization...
[2023-03-04 11:34:00,636] INFO in command_line: Performing day-ahead forecast optimization
[2023-03-04 11:34:00,645] INFO in optimization: Perform optimization for the day-ahead

Hassos is logging:

Logger: homeassistant.components.shell_command
Source: components/shell_command/__init__.py:86
Integration: Shell Command (documentation, issues)
First occurred: 11:34:51 (1 occurrences)
Last logged: 11:34:51

Timed out running command: `curl -i -H "Content-Type: application/json" -X POST -d '{"load_cost_forecast":{{((state_attr('sensor.nordpool', 'raw_today') | map(attribute='value') | list + state_attr('sensor.nordpool', 'raw_tomorrow') | map(attribute='value') | list))[now().hour:][:24] }},"prod_price_forecast":{{((state_attr('sensor.nordpool', 'raw_today') | map(attribute='value') | list + state_attr('sensor.nordpool', 'raw_tomorrow') | map(attribute='value') | list))[now().hour:][:24]}}}' http://localhost:5000/action/dayahead-optim`, after: 60s
Traceback (most recent call last):
  File "/usr/local/lib/python3.10/asyncio/streams.py", line 501, in _wait_for_data
    await self._waiter
asyncio.exceptions.CancelledError

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/shell_command/__init__.py", line 87, in async_service_handler
    stdout_data, stderr_data = await process.communicate()
  File "/usr/local/lib/python3.10/asyncio/subprocess.py", line 195, in communicate
    stdin, stdout, stderr = await tasks.gather(stdin, stdout, stderr)
asyncio.exceptions.CancelledError

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/shell_command/__init__.py", line 86, in async_service_handler
    async with async_timeout.timeout(COMMAND_TIMEOUT):
  File "/usr/local/lib/python3.10/site-packages/async_timeout/__init__.py", line 129, in __aexit__
    self._do_exit(exc_type)
  File "/usr/local/lib/python3.10/site-packages/async_timeout/__init__.py", line 212, in _do_exit
    raise asyncio.TimeoutError
asyncio.exceptions.TimeoutError
overas commented 1 year ago

For testing I loggged into the main Home Assistant Docker container and tried the curl command in the bash shell following this guide:

Install [community "SSH & Web Terminal" addon](https://github.com/hassio-addons/addon-ssh/blob/main/ssh/DOCS.md) (not the official "Terminal & SSH" addon!) and configure your credentials. Note: the addon will fail to start if you use an insecure password so it's better to configure it with public key authentication.

Disable "Protection mode" in the addon's configuration.

At the shell, log into the main Home Assistant Docker container:

docker exec -it homeassistant bash

I used verbose mode in curl:

bash-5.1# curl -i -v -H \"Content-Type: application/json\" -X POST -d '{\"load_cost_forecast\":{{((state_attr('sensor.nordpool', 'raw_today') | map(attribute='value') | list  + state_attr('sensor.nordpool', 'raw_tomorrow') | map(attribute='value') | list))[now().hour:][:24] }},\"prod_price_forecast\":{{((state_attr('sensor.nordpool', 'raw_today') | map(attribute='value') | list  + state_attr('sensor.nordpool', 'raw_tomorrow') | map(attribute='value') | list))[now().hour:][:24]}}}' http://localhost:5000/action/dayahead-optim
Note: Unnecessary use of -X or --request, POST is already inferred.
* Could not resolve host: application
* Closing connection 0
curl: (6) Could not resolve host: application
Note: Unnecessary use of -X or --request, POST is already inferred.
*   Trying 127.0.0.1:5000...
* Connected to localhost (127.0.0.1) port 5000 (#1)
> POST /action/dayahead-optim HTTP/1.1
> Host: localhost:5000
> User-Agent: curl/7.83.1
> Accept: */*
> Content-Length: 389
> Content-Type: application/x-www-form-urlencoded
>
* Mark bundle as not supporting multiuse
< HTTP/1.1 400 BAD REQUEST
HTTP/1.1 400 BAD REQUEST
< Content-Length: 167
Content-Length: 167
< Content-Type: text/html; charset=utf-8
Content-Type: text/html; charset=utf-8
< Date: Sat, 04 Mar 2023 10:47:57 GMT
Date: Sat, 04 Mar 2023 10:47:57 GMT
< Server: waitress
Server: waitress

<
<!doctype html>
<html lang=en>
<title>400 Bad Request</title>
<h1>Bad Request</h1>
<p>The browser (or proxy) sent a request that this server could not understand.</p>
* Connection #1 to host localhost left intact
bash-5.1#

Emhass server did not reply to the curl command:

s6-rc: info: service s6rc-oneshot-runner: starting
s6-rc: info: service s6rc-oneshot-runner successfully started
s6-rc: info: service fix-attrs: starting
s6-rc: info: service fix-attrs successfully started
s6-rc: info: service legacy-cont-init: starting
s6-rc: info: service legacy-cont-init successfully started
s6-rc: info: service legacy-services: starting
services-up: info: copying legacy longrun emhass (no readiness notification)
s6-rc: info: service legacy-services successfully started
[2023-03-04 11:46:23,713] INFO in web_server: Launching the emhass webserver at: http://0.0.0.0:5000
[2023-03-04 11:46:23,714] INFO in web_server: Home Assistant data fetch will be performed using url: http://supervisor/core/api
[2023-03-04 11:46:23,715] INFO in web_server: The data path is: /share
[2023-03-04 11:46:23,720] INFO in web_server: Using core emhass version: 0.3.36
davidusb-geek commented 1 year ago

So that error means that your list is not long enough. Check this post from an iser that effectively implemented this: https://community.home-assistant.io/t/emhass-an-energy-management-for-home-assistant/338126/113?u=davidusb

overas commented 1 year ago

Nordpool has updated the today and tomorrow prices now. I tried to send the two list values:

bash-5.1# curl -v -i -H \"Content-Type: application/json\" -X POST -d '{\"load_cost_forecast\":[2.21, 2.26, 2.28, 2.34, 2.44, 2.48, 2.47, 2.45, 2.43, 2.4, 2.37, 2.35, 2.33, 2.32, 2.34, 2.32, 2.33, 2.35, 2.36, 2.39, 2.39, 2.35, 2.38, 2.38],\"prod_price_forecast\":[2.21, 2.26, 2.28, 2.34, 2.44, 2.48, 2.47, 2.45, 2.43, 2.4, 2.37, 2.35, 2.33, 2.32, 2.34, 2.32, 2.33, 2.35, 2.36, 2.39, 2.39, 2.35, 2.38, 2.38]}' http://localhost:5000/action/dayahead-optim
Note: Unnecessary use of -X or --request, POST is already inferred.
* Could not resolve host: application
* Closing connection 0
curl: (6) Could not resolve host: application
Note: Unnecessary use of -X or --request, POST is already inferred.
*   Trying 127.0.0.1:5000...
* Connected to localhost (127.0.0.1) port 5000 (#1)
> POST /action/dayahead-optim HTTP/1.1
> Host: localhost:5000
> User-Agent: curl/7.83.1
> Accept: */*
> Content-Length: 336
> Content-Type: application/x-www-form-urlencoded
>
* Mark bundle as not supporting multiuse
< HTTP/1.1 400 BAD REQUEST
HTTP/1.1 400 BAD REQUEST
< Content-Length: 167
Content-Length: 167
< Content-Type: text/html; charset=utf-8
Content-Type: text/html; charset=utf-8
< Date: Sat, 04 Mar 2023 12:26:14 GMT
Date: Sat, 04 Mar 2023 12:26:14 GMT
< Server: waitress
Server: waitress

<
<!doctype html>
<html lang=en>
<title>400 Bad Request</title>
<h1>Bad Request</h1>
<p>The browser (or proxy) sent a request that this server could not understand.</p>
* Connection #1 to host localhost left intact
bash-5.1#

Emhass server logs:

s6-rc: info: service s6rc-oneshot-runner: starting
s6-rc: info: service s6rc-oneshot-runner successfully started
s6-rc: info: service fix-attrs: starting
s6-rc: info: service fix-attrs successfully started
s6-rc: info: service legacy-cont-init: starting
s6-rc: info: service legacy-cont-init successfully started
s6-rc: info: service legacy-services: starting
services-up: info: copying legacy longrun emhass (no readiness notification)
s6-rc: info: service legacy-services successfully started
[2023-03-04 13:25:51,058] INFO in web_server: Launching the emhass webserver at: http://0.0.0.0:5000
[2023-03-04 13:25:51,058] INFO in web_server: Home Assistant data fetch will be performed using url: http://supervisor/core/api
[2023-03-04 13:25:51,059] INFO in web_server: The data path is: /share
[2023-03-04 13:25:51,063] INFO in web_server: Using core emhass version: 0.3.36
davidusb-geek commented 1 year ago

Don't launch like that, just launch the HA service for shell command using the Services tab. As you are doing you are not able to reach the host.

davidusb-geek commented 1 year ago

And refresh the add-on logs

overas commented 1 year ago

Launching the shell_command from Services: image

shell_command:
  publish_data: "curl -i -H 'Content-Type:application/json' -X POST -d '{}' http://localhost:5000/action/publish-data"

  trigger_nordpool_forecast: "curl -i -H \"Content-Type: application/json\" -X POST -d '{\"load_cost_forecast\":{{((state_attr('sensor.nordpool', 'raw_today') | map(attribute='value') | list  + state_attr('sensor.nordpool', 'raw_tomorrow') | map(attribute='value') | list))[now().hour:][:24] }},\"prod_price_forecast\":{{((state_attr('sensor.nordpool', 'raw_today') | map(attribute='value') | list  + state_attr('sensor.nordpool', 'raw_tomorrow') | map(attribute='value') | list))[now().hour:][:24]}}}' http://localhost:5000/action/dayahead-optim"

EMhass log:

s6-rc: info: service s6rc-oneshot-runner: starting
s6-rc: info: service s6rc-oneshot-runner successfully started
s6-rc: info: service fix-attrs: starting
s6-rc: info: service fix-attrs successfully started
s6-rc: info: service legacy-cont-init: starting
s6-rc: info: service legacy-cont-init successfully started
s6-rc: info: service legacy-services: starting
services-up: info: copying legacy longrun emhass (no readiness notification)
s6-rc: info: service legacy-services successfully started
[2023-03-04 14:20:33,780] INFO in web_server: Launching the emhass webserver at: http://0.0.0.0:5000
[2023-03-04 14:20:33,780] INFO in web_server: Home Assistant data fetch will be performed using url: http://supervisor/core/api
[2023-03-04 14:20:33,781] INFO in web_server: The data path is: /share
[2023-03-04 14:20:33,786] INFO in web_server: Using core emhass version: 0.3.36
[2023-03-04 14:20:49,070] INFO in command_line: Setting up needed data
[2023-03-04 14:20:49,169] INFO in forecast: Retrieving weather forecast data using method = scrapper
[2023-03-04 14:20:53,726] INFO in forecast: Retrieving data from hass for load forecast using method = naive
[2023-03-04 14:20:53,728] INFO in retrieve_hass: Retrieve hass get data method initiated...
[2023-03-04 14:20:56,769] INFO in web_server:  >> Performing dayahead optimization...
[2023-03-04 14:20:56,769] INFO in command_line: Performing day-ahead forecast optimization
[2023-03-04 14:20:56,813] INFO in optimization: Perform optimization for the day-ahead

Hassos log:

Logger: homeassistant.components.shell_command
Source: components/shell_command/__init__.py:86
Integration: Shell Command (documentation, issues)
First occurred: 14:21:49 (1 occurrences)
Last logged: 14:21:49

Timed out running command: `curl -i -H "Content-Type: application/json" -X POST -d '{"load_cost_forecast":{{((state_attr('sensor.nordpool', 'raw_today') | map(attribute='value') | list + state_attr('sensor.nordpool', 'raw_tomorrow') | map(attribute='value') | list))[now().hour:][:24] }},"prod_price_forecast":{{((state_attr('sensor.nordpool', 'raw_today') | map(attribute='value') | list + state_attr('sensor.nordpool', 'raw_tomorrow') | map(attribute='value') | list))[now().hour:][:24]}}}' http://localhost:5000/action/dayahead-optim`, after: 60s
Traceback (most recent call last):
  File "/usr/local/lib/python3.10/asyncio/streams.py", line 501, in _wait_for_data
    await self._waiter
asyncio.exceptions.CancelledError

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/shell_command/__init__.py", line 87, in async_service_handler
    stdout_data, stderr_data = await process.communicate()
  File "/usr/local/lib/python3.10/asyncio/subprocess.py", line 195, in communicate
    stdin, stdout, stderr = await tasks.gather(stdin, stdout, stderr)
asyncio.exceptions.CancelledError

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/shell_command/__init__.py", line 86, in async_service_handler
    async with async_timeout.timeout(COMMAND_TIMEOUT):
  File "/usr/local/lib/python3.10/site-packages/async_timeout/__init__.py", line 129, in __aexit__
    self._do_exit(exc_type)
  File "/usr/local/lib/python3.10/site-packages/async_timeout/__init__.py", line 212, in _do_exit
    raise asyncio.TimeoutError
asyncio.exceptions.TimeoutError
davidusb-geek commented 1 year ago

Ok thanks, so your're timing out! From the logs we cannot see any errors from inside EMHASS. It is just that it doesn't seem to be able to finish the optimization. From your config I see that you are using the GLPK solver, why is that? May be that's the problem. Try to use the default CBC solver. May be that your optimization problem is just to big. How many deferrable loads are you trying to optimize? Do you have also a battery?

overas commented 1 year ago

I do not have battery, but I have solarpanels. Today I have 8 deferrable loads (6 heating cabel, 1 heat pump, 1 water heater).

My hardware is a Home Assistant Yellow with Raspberry Pi CM4 module. In the emhass documentation you have written this:

Troubleshooting Some problems may arise from solver related issues in the Pulp package. It was found that for arm64 architectures (ie. Raspberry Pi4, 64 bits) the default solver is not avaliable. A workaround is to use another solver. The glpk solver is an option.

So I changed to GLPK_CMD and path None to try to solve the problem.

I have now changed to COIN_CMD and path: /usr/bin/cbc image

and the forecast data are passed to emhass, but I get "timing out" i the hassos log. Tt doesn't seem to be able to finish the optimization.

s6-rc: info: service s6rc-oneshot-runner: starting
s6-rc: info: service s6rc-oneshot-runner successfully started
s6-rc: info: service fix-attrs: starting
s6-rc: info: service fix-attrs successfully started
s6-rc: info: service legacy-cont-init: starting
s6-rc: info: service legacy-cont-init successfully started
s6-rc: info: service legacy-services: starting
services-up: info: copying legacy longrun emhass (no readiness notification)
s6-rc: info: service legacy-services successfully started
[2023-03-04 14:59:19,438] INFO in web_server: Launching the emhass webserver at: http://0.0.0.0:5000
[2023-03-04 14:59:19,439] INFO in web_server: Home Assistant data fetch will be performed using url: http://supervisor/core/api
[2023-03-04 14:59:19,441] INFO in web_server: The data path is: /share
[2023-03-04 14:59:19,445] INFO in web_server: Using core emhass version: 0.3.36
[2023-03-04 14:59:41,275] INFO in command_line: Setting up needed data
[2023-03-04 14:59:41,371] INFO in forecast: Retrieving weather forecast data using method = scrapper
[2023-03-04 14:59:44,864] INFO in forecast: Retrieving data from hass for load forecast using method = naive
[2023-03-04 14:59:44,866] INFO in retrieve_hass: Retrieve hass get data method initiated...
[2023-03-04 14:59:48,161] INFO in web_server:  >> Performing dayahead optimization...
[2023-03-04 14:59:48,162] INFO in command_line: Performing day-ahead forecast optimization
[2023-03-04 14:59:48,198] INFO in optimization: Perform optimization for the day-ahead
[2023-03-04 15:00:35,074] INFO in web_server: EMHASS server online, serving index.html...
[2023-03-04 15:00:39,015] INFO in web_server: EMHASS server online, serving index.html...
[2023-03-04 15:00:49,804] INFO in optimization: Status: Optimal
[2023-03-04 15:00:49,804] INFO in optimization: Total value of the Cost function = -254.56
[2023-03-04 15:01:00,428] INFO in web_server: EMHASS server online, serving index.html...
[2023-03-04 15:01:19,953] INFO in web_server: EMHASS server online, serving index.html...

image

Logger: homeassistant.components.shell_command
Source: components/shell_command/__init__.py:86
Integration: Shell Command (documentation, issues)
First occurred: 15:00:41 (1 occurrences)
Last logged: 15:00:41

Timed out running command: `curl -i -H "Content-Type: application/json" -X POST -d '{"load_cost_forecast":{{((state_attr('sensor.nordpool', 'raw_today') | map(attribute='value') | list + state_attr('sensor.nordpool', 'raw_tomorrow') | map(attribute='value') | list))[now().hour:][:24] }},"prod_price_forecast":{{((state_attr('sensor.nordpool', 'raw_today') | map(attribute='value') | list + state_attr('sensor.nordpool', 'raw_tomorrow') | map(attribute='value') | list))[now().hour:][:24]}}}' http://localhost:5000/action/dayahead-optim`, after: 60s
Traceback (most recent call last):
  File "/usr/local/lib/python3.10/asyncio/streams.py", line 501, in _wait_for_data
    await self._waiter
asyncio.exceptions.CancelledError

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/shell_command/__init__.py", line 87, in async_service_handler
    stdout_data, stderr_data = await process.communicate()
  File "/usr/local/lib/python3.10/asyncio/subprocess.py", line 195, in communicate
    stdin, stdout, stderr = await tasks.gather(stdin, stdout, stderr)
asyncio.exceptions.CancelledError

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/shell_command/__init__.py", line 86, in async_service_handler
    async with async_timeout.timeout(COMMAND_TIMEOUT):
  File "/usr/local/lib/python3.10/site-packages/async_timeout/__init__.py", line 129, in __aexit__
    self._do_exit(exc_type)
  File "/usr/local/lib/python3.10/site-packages/async_timeout/__init__.py", line 212, in _do_exit
    raise asyncio.TimeoutError
asyncio.exceptions.TimeoutError
overas commented 1 year ago

I forgot to mention it, but my HA Yellow have only 2GB with RAM. Maybe Pulp need more RAM when doing the optimization?

davidusb-geek commented 1 year ago

Ok so look no further. Your optimization problem is just too big. The Linear Programming has just too many equations to solve for 8 deferrable loads and that type of solver. You have two options now: Option #1: you can try to get the CBC solver to work with PULP_CBC_CMD or... Option #2: reduce your problem size by either reducing the number of deferrable loads or by reducing the time period of your optimization. To reduce the optimization period you can switch to MPC instead of dayahead optimization. Look to the docs examples in order to help you set MPC. You will just need to pass some additional params, most notably the prediction horizon, fix to something like 6h and launch the MPC every 6 hours. This way you will reduce the optimization problem size.

overas commented 1 year ago

Thanks for your help David. I am going to try the options. If I upgrade my HA Yellow to 8 GB RAM or change to a Intel NUC will it help ?

davidusb-geek commented 1 year ago

The RAM may help but not guaranteed. The solver could really help, the CBC is way more efficient. If you have already set the dayahead optimization, the MPC is really not that difficult to set. You just need to change a little bit your shell command.

overas commented 1 year ago

Thank you for your help. I going to try the MPC controller.

overas commented 1 year ago

Using the MPC controller with the prediction horizon fixed to 6 hour and a automation which do the optimization every 6 hour fixed the problem when the optimization is timing out:

trigger_nordpool_mpc: "curl -i -H \"Content-Type: application/json\" -X POST -d '{\"load_cost_forecast\":{{((state_attr('sensor.nordpool', 'raw_today') | map(attribute='value') | list + state_attr('sensor.nordpool', 'raw_tomorrow') | map(attribute='value') | list))[now().hour:][:24] }},\"prod_price_forecast\":{{((state_attr('sensor.nordpool', 'raw_today') | map(attribute='value') | list + state_attr('sensor.nordpool', 'raw_tomorrow') | map(attribute='value') | list))[now().hour:][:24]}}, \"prediction_horizon\":6, \"def_total_hours\":[5,8,8,8,8,8,8,8]}' http://localhost:5000/action/naive-mpc-optim"

davidusb-geek commented 1 year ago

Great, just be careful to maybe re-evaluate the def_total_hours in this case for MPC those will be the total number of hours inside the prediction horizon window, in your case 6h.

overas commented 1 year ago

Here are the updated shell commands with total number of hours inside the prediction horizon window, in my case 6h: Waterheater: 2 hours Floorheating: 3 hours \"def_total_hours\":[2,3,3,3,3,3,3,3]

shell_command:
  publish_data: "curl -i -H \"Content-Type: application/json\" -X POST -d '{}' http://localhost:5000/action/publish-data"

  trigger_nordpool_forecast: "curl -i -H \"Content-Type: application/json\" -X POST -d '{\"load_cost_forecast\":{{((state_attr('sensor.nordpool', 'raw_today') | map(attribute='value') | list  + state_attr('sensor.nordpool', 'raw_tomorrow') | map(attribute='value') | list))[now().hour:][:24] }},\"prod_price_forecast\":{{((state_attr('sensor.nordpool', 'raw_today') | map(attribute='value') | list  + state_attr('sensor.nordpool', 'raw_tomorrow') | map(attribute='value') | list))[now().hour:][:24]}}}' http://localhost:5000/action/dayahead-optim"

  trigger_nordpool_mpc: "curl -i -H \"Content-Type: application/json\" -X POST -d '{\"load_cost_forecast\":{{((state_attr('sensor.nordpool', 'raw_today') | map(attribute='value') | list + state_attr('sensor.nordpool', 'raw_tomorrow') | map(attribute='value') | list))[now().hour:][:24] }},\"prod_price_forecast\":{{((state_attr('sensor.nordpool', 'raw_today') | map(attribute='value') | list  + state_attr('sensor.nordpool', 'raw_tomorrow') | map(attribute='value') | list))[now().hour:][:24]}}, \"prediction_horizon\":6, \"def_total_hours\":[2,3,3,3,3,3,3,3]}' http://localhost:5000/action/naive-mpc-optim"

  trigger_entsoe_mpc: "curl -i -H \"Content-Type: application/json\" -X POST -d '{\"load_cost_forecast\":{{((state_attr('sensor.entsoe_average_electricity_price_today', 'prices_today') | map(attribute='price') | list + state_attr('sensor.entsoe_average_electricity_price_today', 'prices_tomorrow') | map(attribute='price') | list))[now().hour:][:24] }},\"prod_price_forecast\":{{((state_attr('sensor.entsoe_average_electricity_price_today', 'prices_today') | map(attribute='price') | list  + state_attr('sensor.entsoe_average_electricity_price_today', 'prices_tomorrow') | map(attribute='price') | list))[now().hour:][:24]}}, \"prediction_horizon\":6, \"def_total_hours\":[2,3,3,3,3,3,3,3]}' http://localhost:5000/action/naive-mpc-optim"
davidusb-geek commented 1 year ago

👍