wnsm: Error on device update – KeyError: 'values'

raoulbhatia commented 8 months ago

I added an existing Smart Meter today and observe the following error when the component tries to import historical data.

tag: v1.2.0
Home Assistant 2023.9.3

2023-10-09 20:55:22.156 WARNING (MainThread) [custom_components.wnsm.statistics_sensor] Starting import of historical data. This might take some time.
2023-10-09 20:55:23.370 ERROR (MainThread) [homeassistant.components.sensor] wnsm: Error on device update!                                                    Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 573, in _async_add_entity                                                          await entity.async_device_update(warning=False)
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 936, in async_device_update                                                                 await self.async_update()
  File "/config/custom_components/wnsm/statistics_sensor.py", line 126, in async_update                                                                           await self._import_historical_data(smartmeter)
  File "/config/custom_components/wnsm/statistics_sensor.py", line 150, in _import_historical_data
    for value in recording['values']:                                                                                                                                          ~~~~~~~~~^^^^^^^^^^
KeyError: 'values'

donkristo commented 8 months ago

Same here. HA v2023.10.3

reox commented 8 months ago

looks like they changed that... have to look into that!

raoulbhatia commented 8 months ago

Please let us know how we can support!

donkristo commented 8 months ago

In my case it could be because my smartmeter is not yet exporting any usage data to csv. maybe this helps.

raoulbhatia commented 8 months ago

Thanks @DarwinsBuddy, the error is now gone.

FYI there is a typo in the error message: hsitorical vs. historical.

Lastly, if I log into the account at https://smartmeter-web.wienernetze.at/ I am able do download historical data as a CSV.

Would you know what the issue might be that the component is not able to retrieve/import the historical data?

DarwinsBuddy commented 8 months ago

@raoulbhatia Thanks for reading more careful than I did :sweat_smile: I'll fix it with the next release :+1:

I'll have to investigate, maybe the API response changed again without releasing a new version.

DarwinsBuddy commented 8 months ago

@raoulbhatia I just checked if the API changed somehow and cannot confirm.

Could it be that you have different "zaehlwerke", i.e. different entities of counting your consumption?

DarwinsBuddy commented 8 months ago

could you possibly hit F12 on your smart meter webinterface, navigate to your Network tab, select some month to export and copy the response of the underlying request here (depicted in attached screenshot)?

2023-10-28_12-23

raoulbhatia commented 8 months ago

Will do so within the next hour

DarwinsBuddy commented 8 months ago

Furthermore: Is there anything suspicious in your ha log?

raoulbhatia commented 8 months ago

Reg the web request, I see requests:

OPTIONS Request – returns only response headers, no response body

OPTIONS https://api.wstw.at/gateway/WN_SMART_METER_PORTAL_API_B2B/1.0/zaehlpunkte/12020xxxxx/AT001000000000000000100000xxxxxxx/messwerte?datumVon=2023-06-01&datumBis=2023-06-30&wertetyp=DAY

Response headers

HTTP/1.1 200 OK
Date: Sat, 28 Oct 2023 11:24:18 GMT
Server: httpd
content-length: 0
access-control-max-age: -1
access-control-allow-origin: https://smartmeter-web.wienernetze.at
access-control-allow-methods: GET
access-control-allow-headers: authorization,expires,x-gateway-apikey,cache-control,pragma
strict-transport-security: max-age=15724800; includeSubDomains
set-cookie: LB_STICKY_SESSION=xxxxxxxxx; Path=/; Secure; HttpOnly
Keep-Alive: timeout=4, max=300
Connection: Keep-Alive

GET request – returns response headers (omitted) and response body.

GET https://api.wstw.at/gateway/WN_SMART_METER_PORTAL_API_B2B/1.0/zaehlpunkte/12020xxxxx/AT001000000000000000100000xxxxxxx/messwerte?datumVon=2023-06-01&datumBis=2023-06-30&wertetyp=DAY

Response body (shortened)

{
  "zaehlwerke": [
    {
      "obisCode": "1-1:1.9.0",
      "einheit": "WH",
      "messwerte": [
        {
          "messwert": 7459.0,
          "zeitVon": "2023-05-31T22:00:00.000Z",
          "zeitBis": "2023-06-01T22:00:00.000Z",
          "qualitaet": "VAL"
        },
        {
          "messwert": 4776.0,
          "zeitVon": "2023-06-01T22:00:00.000Z",
          "zeitBis": "2023-06-02T22:00:00.000Z",
          "qualitaet": "VAL"
        },
[...]
        {
          "messwert": 8241.0,
          "zeitVon": "2023-06-29T22:00:00.000Z",
          "zeitBis": "2023-06-30T22:00:00.000Z",
          "qualitaet": "VAL"
        }
      ]
    }
  ],
  "zaehlpunkt": "AT001000000000000000100000xxxxxxx"
}

raoulbhatia commented 8 months ago

Also, I do not see anything suspicious in the home assistant logs, see below

Home Assistant 2023.10.3
Running in Docker on an 32bit RPi
Note: Some devices are offline

$ docker logs -f homeassistant 2>&1| grep -v better_thermostat  # remove verbose better thermostat logs

2023-10-28 11:31:48.269 WARNING (SyncWorker_4) [homeassistant.loader] We found a custom integration scheduler which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant
2023-10-28 11:31:48.275 WARNING (SyncWorker_4) [homeassistant.loader] We found a custom integration wnsm which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant
2023-10-28 11:32:26.149 WARNING (MainThread) [homeassistant.setup] Setup of zone is taking over 10 seconds.
2023-10-28 11:32:38.017 WARNING (MainThread) [homeassistant.config_entries] Config entry 'HP Officejet Pro XXXX [XXXXX]' for ipp integration not ready yet: Invalid response from API: Timeout occurred while connecting to IPP server.; Retrying in background
2023-10-28 11:32:52.334 WARNING (MainThread) [aioesphomeapi.reconnect_logic] Can't connect to ESPHome API for esp-mobile @ 192.x.x.5: Error connecting to ('192.x.x.5', 6053): [Errno 113] Connect call failed ('192.x.x.5', 6053) (SocketAPIError)
2023-10-28 11:32:53.800 WARNING (MainThread) [custom_components.wnsm.statistics_sensor] Starting import of historical data. This might take some time.
2023-10-28 11:32:54.571 ERROR (MainThread) [homeassistant.components.sensor] wnsm: Error on device update!
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/entity_platform.py", line 573, in _async_add_entity
    await entity.async_device_update(warning=False)
  File "/usr/src/homeassistant/homeassistant/helpers/entity.py", line 991, in async_device_update
    await self.async_update()
  File "/config/custom_components/wnsm/statistics_sensor.py", line 126, in async_update
    await self._import_historical_data(smartmeter)
  File "/config/custom_components/wnsm/statistics_sensor.py", line 150, in _import_historical_data
    raise ValueError("WienerNetze does not report hsitorical data (yet)")
ValueError: WienerNetze does not report hsitorical data (yet)
2023-10-28 11:33:18.178 WARNING (MainThread) [homeassistant.components.kodi.media_player] Unable to connect to Kodi via websocket
  update_hvac_action(self)

DarwinsBuddy commented 8 months ago

that's really odd. It looks like everything should be working correctly, so maybe it has something to do with your response from this API call. We are calling

GET https://api.wstw.at/gateway/WN_SMART_METER_PORTAL_API_B2B/1.0/zaehlpunkte//messwerte?datumVon=2023-06-01&datumBis=2023-06-30&wertetyp=DAY

which returns a list of zaehlpunkte

the webinterface calls and endpoint where it adds the "contractId" and "zaehlpunktnummer" as path parameters, hence

GET https://api.wstw.at/gateway/WN_SMART_METER_PORTAL_API_B2B/1.0/zaehlpunkte/12020xxxxx/AT001000000000000000100000xxxxxxx/messwerte?datumVon=2023-06-01&datumBis=2023-06-30&wertetyp=DAY

which returns an object with presumably just the information for that zaehlpunkt.

I'd like to check if the responses somehow differ in your case. Thus I released a new version 1.3.1 which adds some debug logs.

Could you

Enable debug logs for the wnsm integration
restart home assistant
disable debug logs (you should be presented a save as dialog for the logs)
attach the (anonymized) logs here

I'd very much appreciate it.

raoulbhatia commented 8 months ago

@DarwinsBuddy please find the debug log attached (shortened to exclude better_thermostat). anon.log

What i notice is

the Customer ID 12020xxxxx is missing from the second request

wertetyp=QUARTER_HOUR – my smart meter reports in days, I think (= default?)

REQUEST: https://api.wstw.at/gateway/WN_SMART_METER_PORTAL_API_B2B/1.0/zaehlpunkte/messwerte?zaehlpunkt=AT001000000000000000100000xxxxxxx&datumVon=2020-10-28&datumBis=2023-10-28&wertetyp=QUARTER_HOUR

Cheers, Raoul

DarwinsBuddy commented 8 months ago

alright. I think I know what's up. it seems that this endpoint which we are using is not returning values, but rather the one with the two path Params does.

I'll try to fix this. give me some time

raoulbhatia commented 8 months ago

FYI I fiddled around with the URL and it seems that one needs to pass the proper wertetyp= parameter.

Upon a manual check (copied the web request to a curl command)

If I pass wertetyp=QUARTER_HOUR, it returns a basically empty reply curl -s 'https://api.wstw.at/gateway/WN_SMART_METER_PORTAL_API_B2B/1.0/zaehlpunkte/12020xxxxx/AT001000000000000000100000xxxxxxx/messwerte?datumVon=2023-07-01&datumBis=2023-07-31&wertetyp=QUARTER_HOUR'
If I pass wertetyp=DAY I get actual numbers. curl -s 'https://api.wstw.at/gateway/WN_SMART_METER_PORTAL_API_B2B/1.0/zaehlpunkte/12020xxxxx/AT001000000000000000100000xxxxxxx/messwerte?datumVon=2023-07-01&datumBis=2023-07-31&wertetyp=DAY'

raoulbhatia commented 8 months ago

Might be worth to extract this information from the GET /zaehlpunkte endpoint?

cat resp | jq '.[].zaehlpunkte.[].idexStatus.granularity'
{
  "status": "DAY",
  "canBeChanged": true
}

DarwinsBuddy commented 8 months ago

interesting. so I guess you didn't opt into quarter hourly reports. if that's the reason, I think a fallback to hourly would do the trick.

raoulbhatia commented 8 months ago

Actually, as the granularity is available via the API, why not use the data provided to select the right wertetyp.

Wouldn't this make it more versatile and generic?

DarwinsBuddy commented 8 months ago

since we're calling the /zaehlpunkt endpoint anyway on device update, it's not a big deal to add this. good point. :) I'm on it

DarwinsBuddy commented 8 months ago

@raoulbhatia I released https://github.com/DarwinsBuddy/WienerNetzeSmartmeter/releases/tag/v1.3.2 which should use the "zaehlpunkt"'s granularity setting for pulling historical data. Please upgrade and report back with what you're observing :)

raoulbhatia commented 8 months ago

Will do so in the evening. Thanks!

raoulbhatia commented 8 months ago

@DarwinsBuddy first off, the good news – imports are started 🥳

Now, I see the following "WARNING" for each day of my historic data:

2023-10-29 18:12:05.079 WARNING (MainThread) [custom_components.wnsm.statistics_sensor] Starting import of historical data. This might take some time.
2023-10-29 18:12:05.994 WARNING (MainThread) [custom_components.wnsm.statistics_sensor] Unexpected time step detected in historic data: {'messwert': 2179.0, 'zeitVon': '2023-05-29T22:00:00.000Z', 'zeitBis': '2023-05-30T22:00:00.000Z', 'qualitaet': 'VAL'}
2023-10-29 18:12:05.995 WARNING (MainThread) [custom_components.wnsm.statistics_sensor] Unexpected time step detected in historic data: {'messwert': 4476.0, 'zeitVon': '2023-05-30T22:00:00.000Z', 'zeitBis': '2023-05-31T22:00:00.000Z', 'qualitaet': 'VAL'}
2023-10-29 18:12:05.996 WARNING (MainThread) [custom_components.wnsm.statistics_sensor] Unexpected time step detected in historic data: {'messwert': 7459.0, 'zeitVon': '2023-05-31T22:00:00.000Z', 'zeitBis': '2023-06-01T22:00:00.000Z', 'qualitaet': 'VAL'}
[...]

Shall I open a new issue for this? I guess this is something different/distinct to look at?

Cheers & thanks for working with me through this situation 😁

DarwinsBuddy commented 8 months ago

yes please, open another one for that 😊

I'll have a look if it's still causing troubles

raoulbhatia commented 8 months ago

See #194

DarwinsBuddy / WienerNetzeSmartmeter

wnsm: Error on device update – KeyError: 'values' #193