pv_opt icon indicating copy to clipboard operation
pv_opt copied to clipboard

Another TZ issue with todays saving session

Open swests opened this issue 4 months ago • 8 comments

Describe the bug Seeing an issue with the saving session today

PV_OPT.LOG

2025-09-08 17:36:19.820561 INFO: event_value = 10.0
--
2025-09-08 17:36:19.819839 INFO: event_end = 2025-09-08 16:30:00+00:00
2025-09-08 17:36:19.819019 INFO: event_start = 2025-09-08 18:00:00+01:00
2025-09-08 17:36:19.818306 INFO:
2025-09-08 17:36:19.817588 INFO: Recalculating event_start and event_end
2025-09-08 17:36:19.816821 INFO: event_end = 2025-09-08 19:00:00+01:00
2025-09-08 17:36:19.816095 INFO: event_start = 2025-09-08 18:00:00+01:00
2025-09-08 17:36:19.815393 INFO: end = 2025-09-08 16:30:00+00:00
2025-09-08 17:36:19.814684 INFO: start = 2025-09-08 00:00:00+00:00
2025-09-08 17:36:19.813974 INFO:
2025-09-08 17:36:19.813252 INFO: Savings Events debugging

ERROR.LOG

2025-09-08 17:36:19.824564 WARNING pv_opt: ------------------------------------------------------------
--
2025-09-08 17:36:19.824481 WARNING pv_opt: Traceback (most recent call last): File "/usr/lib/python3.11/site-packages/appdaemon/app_management.py", line 162, in initialize_app await utils.run_in_executor(self, init) File "/usr/lib/python3.11/site-packages/appdaemon/utils.py", line 304, in run_in_executor response = future.result() ^^^^^^^^^^^^^^^ File "/usr/lib/python3.11/concurrent/futures/thread.py", line 58, in run result = self.fn(*self.args, **self.kwargs) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.11/site-packages/appdaemon/adbase.py", line 35, in f_app_lock return f(*args, **kw) ^^^^^^^^^^^^^^ File "/homeassistant/appdaemon/apps/pv_opt/pv_opt.py", line 671, in initialize self._cost_actual() File "/homeassistant/appdaemon/apps/pv_opt/pv_opt.py", line 1435, in _cost_actual cost_today = self.contract.net_cost(grid_flow=grid, log=self.debug, day_ahead=False, sum=False) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/homeassistant/appdaemon/apps/pv_opt/pvpy.py", line 673, in net_cost imp_df = self.tariffs["import"].to_df(start=start.floor("30min"), end=end, **kwargs) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/homeassistant/appdaemon/apps/pv_opt/pvpy.py", line 399, in to_df df.loc[event_start:event_end, "unit"] += event_value ~~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.11/site-packages/pandas/core/indexing.py", line 1184, in __getitem__ return self._getitem_tuple(key) ^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.11/site-packages/pandas/core/indexing.py", line 1368, in _getitem_tuple return self._getitem_lowerdim(tup) ^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.11/site-packages/pandas/core/indexing.py", line 1089, in _getitem_lowerdim return getattr(section, self.name)[new_key] ~~~~~~~~~~~~~~~~~~~~~~~~~~~^^^^^^^^^ File "/usr/lib/python3.11/site-packages/pandas/core/indexing.py", line 1191, in __getitem__ return self._getitem_axis(maybe_callable, axis=axis) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.11/site-packages/pandas/core/indexing.py", line 1411, in _getitem_axis return self._get_slice_axis(key, axis=axis) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.11/site-packages/pandas/core/indexing.py", line 1443, in _get_slice_axis indexer = labels.slice_indexer(slice_obj.start, slice_obj.stop, slice_obj.step) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.11/site-packages/pandas/core/indexes/datetimes.py", line 682, in slice_indexer return Index.slice_indexer(self, start, end, step) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.11/site-packages/pandas/core/indexes/base.py", line 6708, in slice_indexer start_slice, end_slice = self.slice_locs(start, end, step=step) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/lib/python3.11/site-packages/pandas/core/indexes/base.py", line 6930, in slice_locs raise ValueError("Both dates must have the same UTC offset") ValueError: Both dates must have the same UTC offset
2025-09-08 17:36:19.821622 WARNING pv_opt: ------------------------------------------------------------
2025-09-08 17:36:19.821554 WARNING pv_opt: Unexpected error running initialize() for pv_opt
2025-09-08 17:36:19.821472 WARNING pv_opt: ------------------------------------------------------------
2025-09-08 17:34:13.556624 WARNING pv_opt: ------------------------------------------------------------
 
ValueError: Both dates must have the same UTC offset
raise ValueError("Both dates must have the same UTC offset")
File "/usr/lib/python3.11/site-packages/pandas/core/indexes/base.py", line 6930, in slice_locs
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
start_slice, end_slice = self.slice_locs(start, end, step=step)
File "/usr/lib/python3.11/site-packages/pandas/core/indexes/base.py", line 6708, in slice_indexer
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
return Index.slice_indexer(self, start, end, step)
File "/usr/lib/python3.11/site-packages/pandas/core/indexes/datetimes.py", line 682, in slice_indexer
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
indexer = labels.slice_indexer(slice_obj.start, slice_obj.stop, slice_obj.step)
File "/usr/lib/python3.11/site-packages/pandas/core/indexing.py", line 1443, in _get_slice_axis
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
return self._get_slice_axis(key, axis=axis)
File "/usr/lib/python3.11/site-packages/pandas/core/indexing.py", line 1411, in _getitem_axis
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
return self._getitem_axis(maybe_callable, axis=axis)
File "/usr/lib/python3.11/site-packages/pandas/core/indexing.py", line 1191, in __getitem__
~~~~~~~~~~~~~~~~~~~~~~~~~~~^^^^^^^^^
return getattr(section, self.name)[new_key]
File "/usr/lib/python3.11/site-packages/pandas/core/indexing.py", line 1089, in _getitem_lowerdim
^^^^^^^^^^^^^^^^^^^^^^^^^^^
return self._getitem_lowerdim(tup)
File "/usr/lib/python3.11/site-packages/pandas/core/indexing.py", line 1368, in _getitem_tuple
^^^^^^^^^^^^^^^^^^^^^^^^
return self._getitem_tuple(key)
File "/usr/lib/python3.11/site-packages/pandas/core/indexing.py", line 1184, in __getitem__
~~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
df.loc[event_start:event_end, "unit"] += event_value
File "/homeassistant/appdaemon/apps/pv_opt/pvpy.py", line 399, in to_df
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
imp_df = self.tariffs["import"].to_df(start=start.floor("30min"), end=end, **kwargs)
File "/homeassistant/appdaemon/apps/pv_opt/pvpy.py", line 673, in net_cost
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
cost_today = self.contract.net_cost(grid_flow=grid, log=self.debug, day_ahead=False, sum=False)
File "/homeassistant/appdaemon/apps/pv_opt/pv_opt.py", line 1435, in _cost_actual
self._cost_actual()
File "/homeassistant/appdaemon/apps/pv_opt/pv_opt.py", line 671, in initialize
^^^^^^^^^^^^^^
return f(*args, **kw)
File "/usr/lib/python3.11/site-packages/appdaemon/adbase.py", line 35, in f_app_lock
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
result = self.fn(*self.args, **self.kwargs)
File "/usr/lib/python3.11/concurrent/futures/thread.py", line 58, in run
^^^^^^^^^^^^^^^
response = future.result()
File "/usr/lib/python3.11/site-packages/appdaemon/utils.py", line 304, in run_in_executor
await utils.run_in_executor(self, init)
File "/usr/lib/python3.11/site-packages/appdaemon/app_management.py", line 162, in initialize_app
2025-09-08 17:34:13.556485 WARNING pv_opt: Traceback (most recent call last):
2025-09-08 17:34:13.554395 WARNING pv_opt: ------------------------------------------------------------
2025-09-08 17:34:13.554272 WARNING pv_opt: Unexpected error running initialize() for pv_opt
2025-09-08 17:34:13.554106 WARNING pv_opt: ------------------------------------------------------------
2025-09-08 17:32:44.064951 WARNING pv_opt: ------------------------------------------------------------
 
ValueError: Both dates must have the same UTC offset
raise ValueError("Both dates must have the same UTC offset")
File "/usr/lib/python3.11/site-packages/pandas/core/indexes/base.py", line 6930, in slice_locs
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
start_slice, end_slice = self.slice_locs(start, end, step=step)
File "/usr/lib/python3.11/site-packages/pandas/core/indexes/base.py", line 6708, in slice_indexer
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
return Index.slice_indexer(self, start, end, step)
File "/usr/lib/python3.11/site-packages/pandas/core/indexes/datetimes.py", line 682, in slice_indexer
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
indexer = labels.slice_indexer(slice_obj.start, slice_obj.stop, slice_obj.step)
File "/usr/lib/python3.11/site-packages/pandas/core/indexing.py", line 1443, in _get_slice_axis
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
return self._get_slice_axis(key, axis=axis)
File "/usr/lib/python3.11/site-packages/pandas/core/indexing.py", line 1411, in _getitem_axis
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
return self._getitem_axis(maybe_callable, axis=axis)
File "/usr/lib/python3.11/site-packages/pandas/core/indexing.py", line 1191, in __getitem__
~~~~~~~~~~~~~~~~~~~~~~~~~~~^^^^^^^^^
return getattr(section, self.name)[new_key]
File "/usr/lib/python3.11/site-packages/pandas/core/indexing.py", line 1089, in _getitem_lowerdim
^^^^^^^^^^^^^^^^^^^^^^^^^^^
return self._getitem_lowerdim(tup)
File "/usr/lib/python3.11/site-packages/pandas/core/indexing.py", line 1368, in _getitem_tuple
^^^^^^^^^^^^^^^^^^^^^^^^
return self._getitem_tuple(key)
File "/usr/lib/python3.11/site-packages/pandas/core/indexing.py", line 1184, in __getitem__
~~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
df.loc[event_start:event_end, "unit"] += event_value
File "/homeassistant/appdaemon/apps/pv_opt/pvpy.py", line 399, in to_df
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
imp_df = self.tariffs["import"].to_df(start=start.floor("30min"), end=end, **kwargs)
File "/homeassistant/appdaemon/apps/pv_opt/pvpy.py", line 673, in net_cost
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
cost_today = self.contract.net_cost(grid_flow=grid, log=self.debug, day_ahead=False, sum=False)
File "/homeassistant/appdaemon/apps/pv_opt/pv_opt.py", line 1435, in _cost_actual
^^^^^^^^^^^^^^^^^^^
cost_today = self._cost_actual().sum()
File "/homeassistant/appdaemon/apps/pv_opt/pv_opt.py", line 2644, in optimise
^^^^^^^^^^^^^^
return f(*args, **kw)
File "/usr/lib/python3.11/site-packages/appdaemon/adbase.py", line 35, in f_app_lock
self.optimise()
File "/homeassistant/appdaemon/apps/pv_opt/pv_opt.py", line 2337, in optimise_event
^^^^^^^^^^^^^^
return f(*args, **kw)
File "/usr/lib/python3.11/site-packages/appdaemon/adbase.py", line 35, in f_app_lock
funcref(args["event"], data, self.AD.events.sanitize_event_kwargs(app, args["kwargs"]))
File "/usr/lib/python3.11/site-packages/appdaemon/threading.py", line 1095, in worker
2025-09-08 17:32:44.064856 WARNING pv_opt: Traceback (most recent call last):
2025-09-08 17:32:44.063646 WARNING pv_opt: ------------------------------------------------------------
2025-09-08 17:32:44.063573 WARNING pv_opt: Worker Ags: {'id': '9bc030cc02cd4cbab7fa848ca2e37690', 'name': 'pv_opt', 'objectid': '69c14331948c4ef3970da15bfe0cc804', 'type': 'event', 'event': 'PV_OPT', 'function': <bound method PVOpt.optimise_event of <pv_opt.PVOpt object at 0x7fd0f70f2fd0>>, 'data': {'metadata': {'origin': 'LOCAL', 'time_fired': '2025-09-08T16:32:32.072661+00:00', 'context': {'id': '01K4N2R1A8CKVB35C146WAKBE6', 'parent_id': None, 'user_id': 'f90d56dbc5da41c6bb0ea75491d9f50e'}}}, 'pin_app': True, 'pin_thread': 0, 'kwargs': {'__thread_id': 'thread-0'}}
2025-09-08 17:32:44.063487 WARNING pv_opt: Unexpected error in worker for App pv_opt:
2025-09-08 17:32:44.063396 WARNING pv_opt: ------------------------------------------------------------

swests avatar Sep 08 '25 16:09 swests

The fix applied in issue #402 didn't work. I'll investigate.

stevebuk1 avatar Sep 08 '25 21:09 stevebuk1

Hi I have hundreds of 12:00:00 INFO: 1618 since the saving event detected.

pv_opt.log

PS. Have tried the Prevent Discharge switch #284 a couple of times during cheaper periods and it worked well. This info is probably of limited use to you as I don't have the complication of EV Charging, etc. EDIT...Might be nice to have this as an automatic 'feature' when the cost of units goes negative, probably a bit of an ask!

Pyinthesky99 avatar Sep 10 '25 11:09 Pyinthesky99

Hi I have hundreds of 12:00:00 INFO: 1618 since the saving event detected.

Sorry, that was a feature of the logging for the savings events, its done at a place thats called a lot of times for all sorts of things.

Yours (and mine) didnt crash as the recalculation part wasnt triggered as it wasnt needed so the times compared were then ok. I've put a fix in my system and will await the next event to see if its worked this time.

stevebuk1 avatar Sep 11 '25 20:09 stevebuk1

No worries, have since stopped/started AppDaemon and that's got rid of them.

Did do an oddity last night when it charged for 10 minutes at 02:30 @14.5ppkWH and then saw the error of it's ways!

pv_opt.log

Pyinthesky99 avatar Sep 14 '25 10:09 Pyinthesky99

Apologies if I am Piggy-backing on this thread and this is not a Time-Zone issue. The grid went down a couple of times yesterday morning and in the afternoon I noticed a scheduled charge of full beans at 10:30pm for 30 mins (19% of battery), a bit odd as the slot at 11:30 was cheaper, also set to charge at 4000w but toping battery up about 10%. I was going to see if it adjusted and how it panned out later but unfortunately the grid went down again just after 4pm and didn't come back until the early hours!

error.log pv_opt.log

I did a prevent discharge at lunchtime so the 'useful' stuff kicks off at 15:30. 15:30:27 INFO: Next charge window starts in 359.5 minutes . Nothing to do. This would be 9:30 GMT, 10:30BST

Am on v4.0.11-Beta-3

Pyinthesky99 avatar Sep 16 '25 09:09 Pyinthesky99

I've put a fix in my system and will await the next event to see if its worked this time.

We haven't had another savings sesssion but have included the fix within v5.0.0-Beta-5, released to support Solcast autodamping.

stevebuk1 avatar Sep 19 '25 21:09 stevebuk1

Hi @stevebuk1 - Have you noted the update to BottleCapDave's Octopus integration? Saving sessions are moving to calendar entries. https://bottlecapdave.github.io/HomeAssistant-OctopusEnergy/architecture_decision_records/0003_move_to_calendar_entities_for_octoplus_events/

swests avatar Oct 12 '25 15:10 swests

Hi @stevebuk1 - Have you noted the update to BottleCapDave's Octopus integration? Saving sessions are moving to calendar entries. https://bottlecapdave.github.io/HomeAssistant-OctopusEnergy/architecture_decision_records/0003_move_to_calendar_entities_for_octoplus_events/

Thanks, hadn't seen this. Will create a separate issue to track.

stevebuk1 avatar Oct 22 '25 22:10 stevebuk1