davidusb-geek / emhass-add-on

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

No data published but logs display data published #45

Closed vdiogo closed 1 year ago

vdiogo commented 1 year ago

Since some days (27June) I don't have data published (and therefore triggering automations) to the EMHASS UI. When checking the logs I can see data published from recent timestamps.

I applied yesterday the latest EMHASS version, but still no updates. These are the most recent logs:

2023-07-02 13:50:01,286 - web_server - INFO -  >> Publishing data...
2023-07-02 13:50:01,287 - web_server - INFO - Publishing data to HASS instance
2023-07-02 13:50:01,875 - web_server - INFO - Successfully posted to sensor.p_pv_forecast = -1.5
2023-07-02 13:50:01,935 - web_server - INFO - Successfully posted to sensor.p_load_forecast = 2427.52
2023-07-02 13:50:01,995 - web_server - INFO - Successfully posted to sensor.p_deferrable0 = 0.0
2023-07-02 13:50:02,042 - web_server - INFO - Successfully posted to sensor.p_grid_forecast = 2429.02
2023-07-02 13:50:02,110 - web_server - INFO - Successfully posted to sensor.total_cost_fun_value = -34.4
2023-07-02 13:50:02,163 - web_server - INFO - Successfully posted to sensor.unit_load_cost = 1.0
2023-07-02 13:50:02,307 - web_server - INFO - Successfully posted to sensor.unit_prod_price = 0.0
2023-07-02 13:55:00,998 - web_server - INFO - Setting up needed data
2023-07-02 13:55:01,422 - web_server - INFO -  >> Publishing data...
2023-07-02 13:55:01,423 - web_server - INFO - Publishing data to HASS instance
2023-07-02 13:55:01,948 - web_server - INFO - Successfully posted to sensor.p_pv_forecast = -1.5
2023-07-02 13:55:02,002 - web_server - INFO - Successfully posted to sensor.p_load_forecast = 2427.52
2023-07-02 13:55:02,056 - web_server - INFO - Successfully posted to sensor.p_deferrable0 = 0.0
2023-07-02 13:55:02,114 - web_server - INFO - Successfully posted to sensor.p_grid_forecast = 2429.02
2023-07-02 13:55:02,198 - web_server - INFO - Successfully posted to sensor.total_cost_fun_value = -34.4
2023-07-02 13:55:02,246 - web_server - INFO - Successfully posted to sensor.unit_load_cost = 1.0
2023-07-02 13:55:02,317 - web_server - INFO - Successfully posted to sensor.unit_prod_price = 0.0
2023-07-02 14:00:00,893 - web_server - INFO - Setting up needed data
2023-07-02 14:00:01,586 - web_server - INFO -  >> Publishing data...

This is latest plot: newplot

davidusb-geek commented 1 year ago

Have you tested restarting your HA instance and even restarting the machine where your HA instance is running?

vdiogo commented 1 year ago

Have you tested restarting your HA instance and even restarting the machine where your HA instance is running?

Yes, did both. Still can see data published in EMHASS logs but not published to the UI or triggering automations

vdiogo commented 1 year ago

I set the DEBUG log level and get the following:

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
Traceback (most recent call last):
  File "/usr/local/lib/python3.9/dist-packages/requests/models.py", line 971, in json
    return complexjson.loads(self.text, **kwargs)
  File "/usr/lib/python3.9/json/__init__.py", line 346, in loads
    return _default_decoder.decode(s)
  File "/usr/lib/python3.9/json/decoder.py", line 340, in decode
    raise JSONDecodeError("Extra data", s, end)
json.decoder.JSONDecodeError: Extra data: line 1 column 4 (char 3)
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
  File "/usr/lib/python3.9/runpy.py", line 197, in _run_module_as_main
    return _run_code(code, main_globals, None,
  File "/usr/lib/python3.9/runpy.py", line 87, in _run_code
    exec(code, run_globals)
  File "/usr/local/lib/python3.9/dist-packages/emhass/web_server.py", line 314, in <module>
    config_hass = response.json()
  File "/usr/local/lib/python3.9/dist-packages/requests/models.py", line 975, in json
    raise RequestsJSONDecodeError(e.msg, e.doc, e.pos)
requests.exceptions.JSONDecodeError: Extra data: line 1 column 4 (char 3)
2023-07-06 22:48:23,432 - web_server - INFO - Launching the emhass webserver at: http://0.0.0.0:5000
2023-07-06 22:48:23,564 - web_server - INFO - Home Assistant data fetch will be performed using url: http://supervisor/core/api
2023-07-06 22:48:23,565 - web_server - INFO - The data path is: /share
2023-07-06 22:48:23,934 - web_server - INFO - Using core emhass version: 0.4.13
waitress   INFO  Serving on http://0.0.0.0:5000
2023-07-06 22:53:52,868 - web_server - INFO - EMHASS server online, serving index.html...
vdiogo commented 1 year ago

I have reinstalled the add-on and updated the configuration to have two (instead of one) deferrable loads. Will be checking on the status and will report back. For now, still displays plots results for same date (26June) but logs don't show the previous error:

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-07-10 15:13:37,079 - web_server - INFO - Launching the emhass webserver at: http://0.0.0.0:5000
2023-07-10 15:13:37,080 - web_server - INFO - Home Assistant data fetch will be performed using url: http://supervisor/core/api
2023-07-10 15:13:37,080 - web_server - INFO - The data path is: /share
2023-07-10 15:13:37,116 - web_server - INFO - Using core emhass version: 0.4.13
waitress   INFO  Serving on http://0.0.0.0:5000
2023-07-10 15:15:00,681 - web_server - INFO - Setting up needed data
2023-07-10 15:15:01,317 - web_server - INFO -  >> Publishing data...
2023-07-10 15:15:01,318 - web_server - INFO - Publishing data to HASS instance
2023-07-10 15:15:01,757 - web_server - INFO - Successfully posted to sensor.p_pv_forecast = -1.5
2023-07-10 15:15:01,806 - web_server - INFO - Successfully posted to sensor.p_load_forecast = 2427.52
2023-07-10 15:15:01,855 - web_server - INFO - Successfully posted to sensor.p_deferrable0 = 0.0
2023-07-10 15:15:01,857 - web_server - ERROR - P_deferrable1 was not found in results DataFrame. Optimization task may need to be relaunched or it did not converged to a solution.
2023-07-10 15:15:01,902 - web_server - INFO - Successfully posted to sensor.p_grid_forecast = 2429.02
2023-07-10 15:15:01,965 - web_server - INFO - Successfully posted to sensor.total_cost_fun_value = -34.4
2023-07-10 15:15:02,014 - web_server - INFO - Successfully posted to sensor.unit_load_cost = 1.0
2023-07-10 15:15:02,061 - web_server - INFO - Successfully posted to sensor.unit_prod_price = 0.0

There is one error shown, which I assume is due to the new deferrable load that was added in the new configuration, which should be gone after some days of data published

vdiogo commented 1 year ago

Still no data showing on the UI, however I'm getting the following errors on the automations running the shell_commands:

Logger: homeassistant.components.shell_command
Source: /usr/src/homeassistant/homeassistant/components/shell_command/__init__.py:117
Integration: Shell Command (documentation, issues)
First occurred: 10 de julho de 2023 às 14:25:03 (7 occurrences)
Last logged: 05:30:28

Error running command: `curl -i -H "Content-Type:application/json" -X POST -d '{}' http://localhost:5000/action/publish-data`, return code: 7
Error running command: `curl -i -H "Content-Type:application/json" -X POST -d '{}' http://localhost:5000/action/dayahead-optim`, return code: 52
NoneType: None
davidusb-geek commented 1 year ago

Did you solved these issues? I'm not able to understand what is going on with your previous messages. Post the add-on logged message for better understanding. What is not working?

vdiogo commented 1 year ago

I can now see the published data (based on day-ahead run I assume):

image

So will close this ticket now. Thanks