BottlecapDave / HomeAssistant-OctopusEnergy

Unofficial Home Assistant integration for interacting with Octopus Energy
https://bottlecapdave.github.io/HomeAssistant-OctopusEnergy/
MIT License
612 stars 61 forks source link

Target Rate Binary Sensors Not Turning on at selected time #764

Closed Daverover66 closed 7 months ago

Daverover66 commented 9 months ago

Describe the bug

This integration has been working flawlessly for months now. However, something happened when Octopus changed their standing charge rates a couple of days ago and when I updated HA to 2024.2.1 and this integration to 10.1.0

I have 6 target rate sensors, 2 of which are not turning on when they reach the selected time. Here is one such target rate sensor where you can clearly see that 6 rates were selected covering a 3 hour period between 3am and 6am.

name: intermittent_best_rates_3_hours_overnight
hours: "3.0"
type: Intermittent
mpan: "*******************"
rolling_target: true
last_rates: true
target_invert_target_rates: false
start_time: "21:00"
end_time: "08:00"
kind: target_rate
account_id: ***************
is_target_export: false
rates_incomplete: false
target_times:
  - value_inc_vat: 0.120855
    start: "2024-02-17T03:00:00+00:00"
    end: "2024-02-17T03:30:00+00:00"
    tariff_code: E-1R-AGILE-23-12-06-N
    is_capped: false
  - value_inc_vat: 0.120855
    start: "2024-02-17T03:30:00+00:00"
    end: "2024-02-17T04:00:00+00:00"
    tariff_code: E-1R-AGILE-23-12-06-N
    is_capped: false
  - value_inc_vat: 0.120855
    start: "2024-02-17T04:00:00+00:00"
    end: "2024-02-17T04:30:00+00:00"
    tariff_code: E-1R-AGILE-23-12-06-N
    is_capped: false
  - value_inc_vat: 0.120855
    start: "2024-02-17T04:30:00+00:00"
    end: "2024-02-17T05:00:00+00:00"
    tariff_code: E-1R-AGILE-23-12-06-N
    is_capped: false
  - value_inc_vat: 0.120855
    start: "2024-02-17T05:00:00+00:00"
    end: "2024-02-17T05:30:00+00:00"
    tariff_code: E-1R-AGILE-23-12-06-N
    is_capped: false
  - value_inc_vat: 0.120855
    start: "2024-02-17T05:30:00+00:00"
    end: "2024-02-17T06:00:00+00:00"
    tariff_code: E-1R-AGILE-23-12-06-N
    is_capped: false
target_times_last_evaluated: "2024-02-16T16:51:09.342491+00:00"
overall_average_cost: 0.12086
overall_min_cost: 0.120855
overall_max_cost: 0.120855
current_duration_in_hours: 0
current_average_cost: null
current_min_cost: null
current_max_cost: null
next_time: "2024-02-17T03:00:00+00:00"
next_duration_in_hours: 3
next_average_cost: 0.120855
next_min_cost: 0.120855
next_max_cost: 0.120855
last_evaluated: "2024-02-16T20:51:11.329478+00:00"
icon: mdi:camera-timer
friendly_name: Octopus Energy Target intermittent_best_rates_3_hours_overnight

This is the history of all target rate sensors over the last 24 hours. The sensor shown above is third one down.

Screenshot_20240217_085338_Home Assistant

This has happened for 2 nights in a row now.

I don't often raise issues so I hope I've given you enough to go on.

In the meantime, I'm going to create another target rate sensor that covers the next few hours and watch what it does.

Reproduction steps

Create a target rate sensor as above and monitor the binary sensor's behaviour over the target times.

Expected behaviour

I expect the target rate binary sensors to turn on at the start of a target rate period and off at the end.

Tariff Code

E-1R-AGILE-23-12-06-N

Integration Version

10.1.0

Home Assistant Version

Core: 2024.2.1

Fresh Install?

After upgrading

Home Assistant Logs

Diagnostics json as follows:

{
  "home_assistant": {
    "installation_type": "Home Assistant OS",
    "version": "2024.2.1",
    "dev": false,
    "hassio": true,
    "virtualenv": false,
    "python_version": "3.12.1",
    "docker": true,
    "arch": "x86_64",
    "timezone": "Europe/London",
    "os_name": "Linux",
    "os_version": "6.1.74-haos",
    "supervisor": "2024.01.1",
    "host_os": "Home Assistant OS 11.5",
    "docker_version": "24.0.7",
    "chassis": "vm",
    "run_as_root": true
  },
  "custom_components": {
    "hildebrandglow_dcc": {
      "version": "1.0.3",
      "requirements": [
        "pyglowmarkt==0.5.5"
      ]
    },
    "hacs": {
      "version": "1.34.0",
      "requirements": [
        "aiogithubapi>=22.10.1"
      ]
    },
    "thermal_comfort": {
      "version": "2.2.2",
      "requirements": []
    },
    "skyq": {
      "version": "v2.11.7",
      "requirements": [
        "pyskyqremote==0.3.26"
      ]
    },
    "octopus_energy": {
      "version": "10.1.0",
      "requirements": []
    },
    "watchman": {
      "version": "0.5.1",
      "requirements": [
        "prettytable==3.0.0"
      ]
    },
    "battery_notes": {
      "version": "2.0.16",
      "requirements": []
    },
    "feedparser": {
      "version": "0.1.11",
      "requirements": [
        "feedparser==6.0.10"
      ]
    },
    "sonoff": {
      "version": "3.5.4",
      "requirements": [
        "pycryptodome>=3.6.6"
      ]
    },
    "fullykiosk": {
      "version": "1.1.0",
      "requirements": [
        "python-fullykiosk==0.0.11"
      ]
    },
    "smartlife": {
      "version": "0.1.0",
      "requirements": [
        "tuya-device-sharing-sdk==0.1.9"
      ]
    },
    "tapo_control": {
      "version": "5.4.13",
      "requirements": [
        "pytapo==3.3.18"
      ]
    },
    "localtuya": {
      "version": "5.2.1",
      "requirements": []
    },
    "frigate": {
      "version": "5.0.1",
      "requirements": [
        "pytz==2022.7"
      ]
    },
    "dwains_dashboard": {
      "version": "3.4.3",
      "requirements": []
    },
    "tuya_local": {
      "version": "2024.2.0",
      "requirements": [
        "tinytuya==1.13.1"
      ]
    },
    "govee": {
      "version": "2023.11.1",
      "requirements": [
        "govee-api-laggat==0.2.2",
        "dacite==1.8.0"
      ]
    },
    "alexa_media": {
      "version": "4.9.2",
      "requirements": [
        "alexapy==1.27.10",
        "packaging>=20.3",
        "wrapt>=1.14.0"
      ]
    },
    "homelink": {
      "version": "v1.3.7",
      "requirements": [
        "pyhomelink==0.1.9",
        "paho-mqtt==1.6.1"
      ]
    },
    "adaptive_lighting": {
      "version": "1.20.0",
      "requirements": [
        "ulid-transform"
      ]
    },
    "better_thermostat": {
      "version": "1.4.0",
      "requirements": []
    },
    "homewhiz": {
      "version": "0.0.6",
      "requirements": [
        "bleak",
        "bleak_retry_connector",
        "dacite",
        "aiohttp",
        "bidict"
      ]
    },
    "solaredge_modbus_multi": {
      "version": "2.4.11-pre.6",
      "requirements": [
        "pymodbus>=3.5.4"
      ]
    },
    "spook_inverse": {
      "version": "2.2.2",
      "requirements": []
    },
    "scheduler": {
      "version": "v0.0.0",
      "requirements": []
    },
    "alarmo": {
      "version": "v1.9.14",
      "requirements": []
    },
    "satellitetracker": {
      "version": "0.0.8",
      "requirements": [
        "n2yoasync==0.0.6"
      ]
    },
    "anniversaries": {
      "version": "5.2.0",
      "requirements": [
        "python-dateutil>=2.8.1",
        "integrationhelper>=0.2.2",
        "voluptuous>=0.12.1"
      ]
    },
    "spook": {
      "version": "2.2.2",
      "requirements": []
    },
    "solaredgeoptimizers": {
      "version": "1.2.2",
      "requirements": [
        "solaredgeoptimizers==1.0.12",
        "jsonfinder==0.4.2"
      ]
    }
  },
  "integration_manifest": {
    "domain": "octopus_energy",
    "name": "Octopus Energy",
    "codeowners": [
      "@bottlecapdave"
    ],
    "config_flow": true,
    "dependencies": [
      "repairs",
      "recorder"
    ],
    "documentation": "https://bottlecapdave.github.io/HomeAssistant-OctopusEnergy",
    "homekit": {},
    "iot_class": "cloud_polling",
    "issue_tracker": "https://github.com/BottlecapDave/HomeAssistant-OctopusEnergy/issues",
    "ssdp": [],
    "version": "10.1.0",
    "zeroconf": [],
    "is_built_in": false
  },
  "data": {
    "id": "A-E0D4DE23",
    "octoplus_enrolled": true,
    "electricity_meter_points": [
      {
        "mpan": "**REDACTED**",
        "meters": [
          {
            "serial_number": "**REDACTED**",
            "is_export": false,
            "is_smart_meter": true,
            "device_id": "**REDACTED**",
            "manufacturer": "106C - EDMI Metering Europe",
            "model": "10E2A100",
            "firmware": "0314B700"
          }
        ],
        "agreements": [
          {
            "start": "2024-02-15T00:00:00+00:00",
            "end": "2025-02-15T00:00:00+00:00",
            "tariff_code": "E-1R-AGILE-23-12-06-N",
            "product_code": "AGILE-23-12-06"
          }
        ]
      },
      {
        "mpan": "**REDACTED**",
        "meters": [
          {
            "serial_number": "**REDACTED**",
            "is_export": true,
            "is_smart_meter": true,
            "device_id": null,
            "manufacturer": "106C - EDMI Metering Europe",
            "model": "10E2A100",
            "firmware": "0314B700"
          }
        ],
        "agreements": [
          {
            "start": "2023-09-28T23:00:00+00:00",
            "end": "2024-09-28T23:00:00+00:00",
            "tariff_code": "E-1R-OUTGOING-FIX-12M-19-05-13-N",
            "product_code": "OUTGOING-FIX-12M-19-05-13"
          }
        ]
      }
    ],
    "gas_meter_points": [
      {
        "mprn": "**REDACTED**",
        "meters": [
          {
            "serial_number": "**REDACTED**",
            "consumption_units": "m\u00b3",
            "is_smart_meter": true,
            "device_id": "**REDACTED**",
            "manufacturer": "106C - EDMI Metering Europe",
            "model": "10F2A100",
            "firmware": "0309BB00"
          }
        ],
        "agreements": [
          {
            "start": "2024-02-15T00:00:00+00:00",
            "end": "2025-02-15T00:00:00+00:00",
            "tariff_code": "G-1R-SILVER-23-12-06-N",
            "product_code": "SILVER-23-12-06"
          }
        ]
      }
    ]
  }
}

There's nothing relevant in the HA logs.

Confirmation

BottlecapDave commented 9 months ago

Sorry you're seeing this.

Do you have any errors in your logs? Have you tried restarting your HA instance or reloading the integration since?

The fact the last evaluated timestamp is quite old (this should be updated roughly every minute) means that HA hasn't fired the event that the entity is listening for, so is probably out of my control I'm afraid.

Daverover66 commented 9 months ago

Not seeing any errors in the logs. I've changed the setting of that target rate sensor to this

name: intermittent_best_rates_3_hours_overnight
hours: "3.0"
type: Intermittent
mpan: "**************"
rolling_target: true
last_rates: true
target_invert_target_rates: false
start_time: "10:30"
end_time: "16:00"
kind: target_rate
account_id: ***************
is_target_export: false
rates_incomplete: false
target_times:
  - value_inc_vat: 0.12348
    start: "2024-02-17T12:00:00+00:00"
    end: "2024-02-17T12:30:00+00:00"
    tariff_code: E-1R-AGILE-23-12-06-N
    is_capped: false
  - value_inc_vat: 0.12285
    start: "2024-02-17T12:30:00+00:00"
    end: "2024-02-17T13:00:00+00:00"
    tariff_code: E-1R-AGILE-23-12-06-N
    is_capped: false
  - value_inc_vat: 0.12285
    start: "2024-02-17T13:00:00+00:00"
    end: "2024-02-17T13:30:00+00:00"
    tariff_code: E-1R-AGILE-23-12-06-N
    is_capped: false
  - value_inc_vat: 0.11991
    start: "2024-02-17T13:30:00+00:00"
    end: "2024-02-17T14:00:00+00:00"
    tariff_code: E-1R-AGILE-23-12-06-N
    is_capped: false
  - value_inc_vat: 0.12285
    start: "2024-02-17T14:30:00+00:00"
    end: "2024-02-17T15:00:00+00:00"
    tariff_code: E-1R-AGILE-23-12-06-N
    is_capped: false
  - value_inc_vat: 0.12348
    start: "2024-02-17T15:30:00+00:00"
    end: "2024-02-17T16:00:00+00:00"
    tariff_code: E-1R-AGILE-23-12-06-N
    is_capped: false
target_times_last_evaluated: "2024-02-17T10:03:02.521043+00:00"
overall_average_cost: 0.12257
overall_min_cost: 0.11991
overall_max_cost: 0.12348
current_duration_in_hours: 0
current_average_cost: null
current_min_cost: null
current_max_cost: null
next_time: "2024-02-17T12:00:00+00:00"
next_duration_in_hours: 2
next_average_cost: 0.1222725
next_min_cost: 0.11991
next_max_cost: 0.12348
last_evaluated: "2024-02-17T10:20:02.520049+00:00"
icon: mdi:camera-timer
friendly_name: Octopus Energy Target intermittent_best_rates_3_hours_overnight

It re-evaluated after I submitted the new times and gave me some target rates, which show up on my rate card

Target Rates

I'll let you know what happens at midday.

If it doesn't turn on I'll restart HA and try again.

Daverover66 commented 9 months ago

Okay. So after reconfiguring the 3 hour intermittent target rate sensor, it worked.

Screenshot_20240217_143734_Home Assistant

However, I've now updated to HA2024.2.2 and set the configuration back to what I need overnight. We'll see what happens tonight .

Daverover66 commented 9 months ago

Sorry, can I just clarify something you said earlier please?

You said "The fact the last evaluated timestamp is quite old (this should be updated roughly every minute)". Does this mean it should update roughly every minute between "start_time" and "end_time", or should it be updating roughly every minute regardless?

** Okay, so I've answered that myself by watching the last_evaluated attribute updating outside the time window ***

BottlecapDave commented 9 months ago

Due to the architecture, the last evaluated timestamp should update roughly every minute, as this is when the sensor checks the calculated rates against the current time and checks to see if the sensor should turn on or off. This is basically the same value as if you look at states.sensor.xxx.last_updated using templates which is HAs underlying tracking of when entities last updated. I added the attribute when I didn't realise the HA method was available.

irata-coder commented 9 months ago

I've just experienced the same thing, albeit I didn't see any correlation with a standing charge change. Reloading the target rate sensor resolved it. This did also happen once last week.

Today, I did add an override tariff just before i noticed the sensor had stopped working.

Unfortunately I don't see any errors in the logs. But there does appear to be a situation where the target rate sensor can occassionally miss turning on.

BottlecapDave commented 9 months ago

As mentioned above, without any errors in the logs there's very little I can think it can be. If the last evaluated timestamp or HA last updated state doesn't change roughly every minute, it implies there's an in issue in HA which is not telling the entity to update. There might be a silent (or debug) error that is occuring on certain entities, but without the logs there is very little I can do.

irata-coder commented 9 months ago

When it happens, the last evaluated ceases to change

Another sensor has the same issue just now, the time is currently 16:34

Target times last evaluated 17 February 2024 at 13:17:04 Last evaluated 17 February 2024 at 14:34:04

I am trying to get any debug i can, but whereever it's happen it does appear to be a silent error so far

Daverover66 commented 9 months ago

This integration was bulletproof in all HA versions up to 2024.1.6. If it's glitching in 2024.2, is it worth raising an issue with the HA team? I don't know what would stop an entity from updating when it should.

My target rates for tonight are set, so we'll see if they work.

Daverover66 commented 9 months ago

Screenshot_20240217_164448_Home Assistant

irata-coder commented 9 months ago

I have found an error that was logged at the exact same time of the last updated time of all the sensors which then ceased to update afterwards. All target rate sensors ceased to update at this point, i'm not seeing issues with any other sensors,

2024-02-17 14:34:52.309 ERROR (MainThread) [homeassistant] Error doing job: Unclosed client session 2024-02-17 14:34:52.310 ERROR (MainThread) [homeassistant] Error doing job: Unclosed connector

Daverover66 commented 9 months ago

My target rate sensor is currently updating roughly every minute so fingers crossed.

I only have to stay up until 11:30pm tonight to make sure it turns on for that first target rate.

BottlecapDave commented 9 months ago

@irata-coder Those issues should be resolved in v10.1.2. However, I'm not sure they're the cause of this issue.

Daverover66 commented 9 months ago

@BottlecapDave Success with last night's target rates. I'll continue to monitor, but I reckon you can safely close this issue as resolved. Thanks.

Screenshot_20240218_075219_Home Assistant

irata-coder commented 9 months ago

@BottlecapDave Ok, that's interesting, thank you.

This looks and feels like a deadlock/race condition, hence why there's no ongoing errors logged. Restarting the rate sensor solves this, but the issue can randomly occur again at somepoint.

For example, could we have a situation whereby the rates are updated at the exact same time the rate sensor handler is iterating the rates. I don't see any mutex around these, or are we confident they can't both execute simulatneously?

BottlecapDave commented 9 months ago

The rate information is updated in a background task (using HA reccommended techniques), which then triggers an event which calls all listening entities to update their data, for which the target rate sensor is one of them and will calculate the next set of target rates (if needed) and then update the state of the sensor based on said target rates. Nothing in the docs suggest any guarding is needed.

I assume you guys are seeing this after manually reloading the integration instead of restarting you HA instance? If so, the only thing I can think of is to see if I can automatically reload the target rate entities after the main account has been reloaded.

irata-coder commented 9 months ago

Since it wasn't something I was expecting, sadly I can't recall exactly what happened but I will take note in future. This has happned more than once now, however, and on different days.

There is a chance I manually reloaded the integration.

I certainly did a home assistant core update. I did notice in the logs that the update hung after downloading for about 15 minutes, waiting for something, then resumed and restarted ok.

What's odd is, when things stop updating, no other itegration was having issues. I'll have a play around over the next few days and see if I can trigger it, I've updated to 10.1.2. At the moment, the last evaluated is ticking along nicely.

Thank you for keeping an eye on this.

Stephens-ely commented 8 months ago

Funnily I had issues early this morning and the expected target_rate sensor didn't trigger - It found a 2 hour period for me and when I looked prior to going to bed it was all looking as usual but when I awoke, I could see the associated automation that is usually triggered by this binary sensor hadn't run.

The history for the sensor shows that whilst it ran on the 20th Feb, it never switched on again on the 21st. Capture

BottlecapDave commented 8 months ago

@Stephens-ely when was the last evaluated timestamp on the sensor? Did you reload the main integration between the dates or update the main config?

Stephens-ely commented 8 months ago

I didn’t at the time because I had to sort some other things out and thought it was just me.

If it happens again, I'll take more note

Brian


From: David Kendall @.> Sent: Wednesday, February 21, 2024 5:38:18 PM To: BottlecapDave/HomeAssistant-OctopusEnergy @.> Cc: Brian @.>; Mention @.> Subject: Re: [BottlecapDave/HomeAssistant-OctopusEnergy] Target Rate Binary Sensors Not Turning on at selected time (Issue #764)

@Stephens-elyhttps://github.com/Stephens-ely when was the last evaluated timestamp on the sensor? Did you reload the main integration between the dates or update the main config?

— Reply to this email directly, view it on GitHubhttps://github.com/BottlecapDave/HomeAssistant-OctopusEnergy/issues/764#issuecomment-1957446444, or unsubscribehttps://github.com/notifications/unsubscribe-auth/A3JPHS5AAWNRCUP4Z73HTU3YUYWIVAVCNFSM6AAAAABDNFACS2VHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMYTSNJXGQ2DMNBUGQ. You are receiving this because you were mentioned.Message ID: @.***>

irata-coder commented 8 months ago

I can recreate this by restarting the integration for the account only, after doing this any target times stop being evaluated.

BottlecapDave commented 7 months ago

Sorry for the late response.

I believe I've rectified this issue in the latest release (v10.2.0) by reloading the target rate and cost tracker sensors upon account updates.