tronikos / opower-hacs

HACS integration for PG&E via Opower
10 stars 2 forks source link

Forbidden request #10

Closed Sudo-Rob closed 1 year ago

Sudo-Rob commented 1 year ago

A few days ago, I installed the integration and had some success with the BGE endpoint. At the same time, I started seeing persistent errors occurring with another integration, NWS (NOAA's National Weather Service). These errors would stop the delivery of weather data, but an HA restart would restore operation until the next forbidden request from the Opower integration.

Here is the log file. I have sanitized it where I think it's necessary:

2023-07-31 01:22:21.243 ERROR (MainThread) [homeassistant.components.hassio.handler] Client error on /addons/a0d7b954_glances/changelog request 500, message='Internal Server Error', url=URL('http://172.30.32.2/addons/a0d7b954_glances/changelog')
2023-07-31 01:22:21.256 ERROR (MainThread) [homeassistant.components.hassio.handler] Client error on /addons/a0d7b954_ssh/changelog request 500, message='Internal Server Error', url=URL('http://172.30.32.2/addons/a0d7b954_ssh/changelog')
2023-07-31 01:22:21.270 ERROR (MainThread) [homeassistant.components.hassio.handler] Client error on /addons/a0d7b954_vscode/changelog request 500, message='Internal Server Error', url=URL('http://172.30.32.2/addons/a0d7b954_vscode/changelog')
2023-07-31 03:04:59.968 ERROR (MainThread) [custom_components.opower.coordinator] Error requesting Opower data: 400, message='Bad Request', url=URL('https://bgec.opower.com/ei/edge/apis/bill-forecast-cws-v1/cws/bgec/customers/xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx/combined-forecast')
2023-07-31 03:05:30.531 ERROR (MainThread) [homeassistant.components.homeassistant_alerts] Error requesting homeassistant_alerts data: 400, message='Bad Request', url=URL('https://alerts.home-assistant.io/alerts.json')
2023-07-31 03:05:47.183 ERROR (MainThread) [custom_components.nws] Error requesting NWS forecast station KBWI data: 400, message='Bad Request', url=URL('https://api.weather.gov/gridpoints/LWX/xxx,xx/forecast')
2023-07-31 03:14:47.141 ERROR (MainThread) [custom_components.nws] Error requesting NWS observation station KBWI data: 400, message='Bad Request', url=URL('https://api.weather.gov/stations/KBWI/observations/')
2023-07-31 03:16:57.082 ERROR (MainThread) [custom_components.nws] Error requesting NWS forecast hourly station KBWI data: 400, message='Bad Request', url=URL('https://api.weather.gov/gridpoints/LWX/xxx,xx/forecast/hourly')
2023-07-31 03:17:47.132 ERROR (MainThread) [custom_components.nws] Error requesting NWS forecast station KBWI data: 400, message='Bad Request', url=URL('https://api.weather.gov/gridpoints/LWX/xxx,xx/forecast')
2023-07-31 03:28:47.113 ERROR (MainThread) [custom_components.nws] Error requesting NWS observation station KBWI data: 400, message='Bad Request', url=URL('https://api.weather.gov/stations/KBWI/observations/')
2023-07-31 03:42:47.116 ERROR (MainThread) [custom_components.nws] Error requesting NWS observation station KBWI data: 400, message='Bad Request', url=URL('https://api.weather.gov/stations/KBWI/observations/')
2023-07-31 03:52:47.129 ERROR (MainThread) [homeassistant.helpers.template] Template variable error: None has no element 0 when rendering '{% if (state_attr('weather.kbwi_daynight', 'forecast')[0].datetime | regex_replace(find='20..-..-...', replace='') | truncate(2,true,'')) | int < 6 -%} True {% else -%} False {% endif %}'
2023-07-31 03:52:47.144 ERROR (MainThread) [homeassistant.helpers.template_entity] TemplateError('UndefinedError: None has no element 0') while processing template 'Template<template=({% if (state_attr('weather.kbwi_daynight', 'forecast')[0].datetime | regex_replace(find='20..-..-...', replace='') | truncate(2,true,'')) | int < 6 -%} True {% else -%} False {% endif %}) renders=54>' for attribute '_state' in entity 'binary_sensor.after_midnight'
2023-07-31 03:52:47.147 ERROR (MainThread) [homeassistant.helpers.template] Template variable error: None has no element 0 when rendering '{{ state_attr('weather.kbwi_daynight', 'forecast')[0].datetime | as_timestamp() | timestamp_custom('%a') }}'
2023-07-31 03:52:47.149 ERROR (MainThread) [homeassistant.helpers.template_entity] TemplateError('UndefinedError: None has no element 0') while processing template 'Template<template=({{ state_attr('weather.kbwi_daynight', 'forecast')[0].datetime | as_timestamp() | timestamp_custom('%a') }}) renders=54>' for attribute '_attr_native_value' in entity 'sensor.datetime2dow'
2023-07-31 03:52:47.151 ERROR (MainThread) [homeassistant.helpers.template] Template variable error: None has no element 0 when rendering '{{ state_attr('weather.kbwi_daynight', 'forecast')[0].datetime }}'
2023-07-31 03:52:47.154 ERROR (MainThread) [homeassistant.helpers.template_entity] TemplateError('UndefinedError: None has no element 0') while processing template 'Template<template=({{ state_attr('weather.kbwi_daynight', 'forecast')[0].datetime }}) renders=54>' for attribute '_attr_native_value' in entity 'sensor.nws_datetime_0'
2023-07-31 03:52:47.157 ERROR (MainThread) [homeassistant.helpers.template] Template variable error: None has no element 0 when rendering '{{ state_attr('weather.kbwi_daynight', 'forecast')[0].detailed_description | truncate(254,true,'…',0) }}'
2023-07-31 03:52:47.159 ERROR (MainThread) [homeassistant.helpers.template_entity] TemplateError('UndefinedError: None has no element 0') while processing template 'Template<template=({{ state_attr('weather.kbwi_daynight', 'forecast')[0].detailed_description | truncate(254,true,'…',0) }}) renders=54>' for attribute '_attr_native_value' in entity 'sensor.nws_daily_summary'
2023-07-31 03:52:47.163 ERROR (MainThread) [homeassistant.helpers.template] Template variable error: None has no element 0 when rendering '{{ state_attr('weather.kbwi_daynight', 'forecast')[0].precipitation_probability }}'
2023-07-31 03:52:47.166 ERROR (MainThread) [homeassistant.helpers.template_entity] TemplateError('UndefinedError: None has no element 0') while processing template 'Template<template=({{ state_attr('weather.kbwi_daynight', 'forecast')[0].precipitation_probability }}) renders=54>' for attribute '_attr_native_value' in entity 'sensor.nws_rain_chance_0'

The issue appears at time 03:04:59.968 when there's a Bad Request logged from the endpoint.

Soon after, the NWS integration generates a series of similar 400errors, which ultimately cause template errors due to the lack of data. I should mention that the 500errors from the NWS endpoint occur at a low rate and are expected and benign. However, I have never seen the three client errors at the top of the log extract until I added the Opower integration, but these do not seem to impair operation of their respective add-ons.

Lastly, I have disabled the Opower integration and will monitor the NWS integration over the next few days to see if it reverts to stable operation.

tronikos commented 1 year ago

Which version of Home Assistant are you running? What installation method?

Sudo-Rob commented 1 year ago

Sorry, I should've included that info.

Version | core-2023.7.3 -- | -- Installation Type | Home Assistant OS
tronikos commented 1 year ago

Can you try changing https://github.com/tronikos/opower-hacs/blob/main/custom_components/opower/coordinator.py#L53 from aiohttp_client.async_get_clientsession(hass) to aiohttp_client.async_create_clientsession(hass)?

Sudo-Rob commented 1 year ago

Done.

image

I'll restart HA and report back as soon as I have some observations.

Thanks.

tronikos commented 1 year ago

Since I'm pretty confident this will fix it, I went ahead and released a new version. Please report back with hopefully a confirmation that this was fixed.

Sudo-Rob commented 1 year ago

After enabling the integration and restarting HA, I now see these:

image

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 283, in _async_refresh
    self.data = await self._async_update_data()
                ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/config/custom_components/opower/coordinator.py", line 67, in _async_update_data
    await self.api.async_login()
  File "/usr/local/lib/python3.11/site-packages/opower/opower.py", line 150, in async_login
    await self.utility.async_login(self.session, self.username, self.password)
  File "/usr/local/lib/python3.11/site-packages/opower/utilities/exelon.py", line 33, in async_login
    async with session.get(
               ^^^^^^^^^^^
AttributeError: 'function' object has no attribute 'get'
2023-07-31 14:55:10.097 ERROR (MainThread) [custom_components.opower.coordinator] Unexpected error fetching Opower data: 'function' object has no attribute 'get'
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 283, in _async_refresh
    self.data = await self._async_update_data()
                ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/config/custom_components/opower/coordinator.py", line 67, in _async_update_data
    await self.api.async_login()
  File "/usr/local/lib/python3.11/site-packages/opower/opower.py", line 150, in async_login
    await self.utility.async_login(self.session, self.username, self.password)
  File "/usr/local/lib/python3.11/site-packages/opower/utilities/exelon.py", line 33, in async_login
    async with session.get(
               ^^^^^^^^^^^
AttributeError: 'function' object has no attribute 'get'
2023-07-31 14:55:20.428 ERROR (MainThread) [custom_components.opower.coordinator] Unexpected error fetching Opower data: 'function' object has no attribute 'get'
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 283, in _async_refresh
    self.data = await self._async_update_data()
                ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/config/custom_components/opower/coordinator.py", line 67, in _async_update_data
    await self.api.async_login()
  File "/usr/local/lib/python3.11/site-packages/opower/opower.py", line 150, in async_login
    await self.utility.async_login(self.session, self.username, self.password)
  File "/usr/local/lib/python3.11/site-packages/opower/utilities/exelon.py", line 33, in async_login
    async with session.get(
               ^^^^^^^^^^^
AttributeError: 'function' object has no attribute 'get'

Should I remove the integration and reload it?

tronikos commented 1 year ago

You need to change line 53 to aiohttp_client.async_create_clientsession(hass) (I forgot earlier to add (hass) at the end). Or better update the integration to the latest version via HACS

Sudo-Rob commented 1 year ago

Here's the latest:

2023-07-31 15:40:51.302 ERROR (MainThread) [custom_components.opower.coordinator] Unexpected error fetching Opower data: 400, message='Bad Request', url=URL('https://secure.bge.com/api/Services/OpowerService.svc/GetOpowerToken')
Traceback (most recent call last):
  File "/usr/local/lib/python3.11/site-packages/opower/opower.py", line 150, in async_login
    await self.utility.async_login(self.session, self.username, self.password)
  File "/usr/local/lib/python3.11/site-packages/opower/utilities/exelon.py", line 90, in async_login
    async with session.post(
  File "/usr/local/lib/python3.11/site-packages/aiohttp/client.py", line 1141, in __aenter__
    self._resp = await self._coro
                 ^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/aiohttp/client.py", line 643, in _request
    resp.raise_for_status()
  File "/usr/local/lib/python3.11/site-packages/aiohttp/client_reqrep.py", line 1005, in raise_for_status
    raise ClientResponseError(
aiohttp.client_exceptions.ClientResponseError: 400, message='Bad Request', url=URL('https://secure.bge.com/api/Services/OpowerService.svc/GetOpowerToken')

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 283, in _async_refresh
    self.data = await self._async_update_data()
                ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/config/custom_components/opower/coordinator.py", line 67, in _async_update_data
    await self.api.async_login()
  File "/usr/local/lib/python3.11/site-packages/opower/opower.py", line 155, in async_login
    raise CannotConnect(err)
opower.exceptions.CannotConnect: 400, message='Bad Request', url=URL('https://secure.bge.com/api/Services/OpowerService.svc/GetOpowerToken')
t: 400, message='Bad Request', url=URL('https://secure.bge.com/api/Services/OpowerService.svc/GetOpowerToken')
Sudo-Rob commented 1 year ago

After downloading v0.0.16, I performed an integration reload followed by an HA restart and now see this:

2023-07-31 15:56:59.679 ERROR (MainThread) [custom_components.opower.coordinator] Unexpected error fetching Opower data: 400, message='Bad Request', url=URL('https://secure.bge.com/api/Services/OpowerService.svc/GetOpowerToken')
Traceback (most recent call last):
  File "/usr/local/lib/python3.11/site-packages/opower/opower.py", line 150, in async_login
    await self.utility.async_login(self.session, self.username, self.password)
  File "/usr/local/lib/python3.11/site-packages/opower/utilities/exelon.py", line 90, in async_login
    async with session.post(
  File "/usr/local/lib/python3.11/site-packages/aiohttp/client.py", line 1141, in __aenter__
    self._resp = await self._coro
                 ^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/aiohttp/client.py", line 643, in _request
    resp.raise_for_status()
  File "/usr/local/lib/python3.11/site-packages/aiohttp/client_reqrep.py", line 1005, in raise_for_status
    raise ClientResponseError(
aiohttp.client_exceptions.ClientResponseError: 400, message='Bad Request', url=URL('https://secure.bge.com/api/Services/OpowerService.svc/GetOpowerToken')

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 283, in _async_refresh
    self.data = await self._async_update_data()
                ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/config/custom_components/opower/coordinator.py", line 67, in _async_update_data
    await self.api.async_login()
  File "/usr/local/lib/python3.11/site-packages/opower/opower.py", line 155, in async_login
    raise CannotConnect(err)
opower.exceptions.CannotConnect: 400, message='Bad Request', url=URL('https://secure.bge.com/api/Services/OpowerService.svc/GetOpowerToken')
2023-07-31 15:57:03.227 ERROR (MainThread) [custom_components.opower.coordinator] Unexpected error fetching Opower data: 400, message='Bad Request', url=URL('https://secure.bge.com/api/Services/OpowerService.svc/GetOpowerToken')
Traceback (most recent call last):
  File "/usr/local/lib/python3.11/site-packages/opower/opower.py", line 150, in async_login
    await self.utility.async_login(self.session, self.username, self.password)
  File "/usr/local/lib/python3.11/site-packages/opower/utilities/exelon.py", line 90, in async_login
    async with session.post(
  File "/usr/local/lib/python3.11/site-packages/aiohttp/client.py", line 1141, in __aenter__
    self._resp = await self._coro
                 ^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/aiohttp/client.py", line 643, in _request
    resp.raise_for_status()
  File "/usr/local/lib/python3.11/site-packages/aiohttp/client_reqrep.py", line 1005, in raise_for_status
    raise ClientResponseError(
aiohttp.client_exceptions.ClientResponseError: 400, message='Bad Request', url=URL('https://secure.bge.com/api/Services/OpowerService.svc/GetOpowerToken')

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 283, in _async_refresh
    self.data = await self._async_update_data()
                ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/config/custom_components/opower/coordinator.py", line 67, in _async_update_data
    await self.api.async_login()
  File "/usr/local/lib/python3.11/site-packages/opower/opower.py", line 155, in async_login
    raise CannotConnect(err)
opower.exceptions.CannotConnect: 400, message='Bad Request', url=URL('https://secure.bge.com/api/Services/OpowerService.svc/GetOpowerToken')
tronikos commented 1 year ago

Can you try the latest 0.0.18?

Sudo-Rob commented 1 year ago

So far, so good.

Clean log. Missing daily updates populated. All entities populated, but monthly's still on 0 (expected, I'd think).

Thanks for the quick solution (fingers crossed, though)!

tronikos commented 1 year ago

Good to hear. Reopen if you encounter an issue.

Sudo-Rob commented 1 year ago

I just experienced a bit of a mess. Here are a few details:

Earlier this evening, I updated to core_2023.8.0 and it seemed to work. However, when I wanted to perform an HA reset, it wouldn't let me. It was complaining with this diagnostic: discovery integration not found. I looked to see if the discovery integration had been in the Integration startup time panel and there were four different types of discovery listed: SSDP, Discovery, DHCP Discovery, and UDP Discovery. So, I'm left wondering why this is happening. So far, I haven't seen anything like it being reported on the community forum or GitHub.

I had loaded Opower v0.0.18, and there would have been another version of this in the new core. Could there have been a conflict that could've affected Discovery? If not, could your most-recent update of the Opower integration have caused a problem whereby there might've been contention for the same resources?

Ultimately, I was forced to revert to core_2023.7.3, but when I did, there was nothing in the config directory--not even a log file. I wound up restoring a full backup I made prior to loading Opower. I'm currently at a point where I'd be loading core_2023.8.0 and reintegrating the Opower integration, but I'm a little gun-shy at this point.

Thoughts?

Thanks in advance.

tronikos commented 1 year ago

I don't see how the integration would mess up discovery since it isn't using it. I upgraded to 2023.8.0 without issues. After the upgrade I removed the config entry, deleted it in HACS, and set it up again using the official integration without any issues. Thee official integration in 2023.8.0 and the one here are exactly the same code anyway.

tronikos commented 1 year ago

I noticed the 2023.8.0 release notes have a breaking change regarding discovery. Likely you need to remove discovery: from your config.

Sudo-Rob commented 1 year ago

Well, I'm embarrassed. I saw the release notes, but didn't realize I had a separate discovery entry in a configuration file. I thought it was loaded by default_config, which I knew I had, but evolves with the updates. Still, I didn't expect the loss of the /config contents.

Apologies for the posts, but thanks for pointing me in the right direction.