Glitch during Overnight Charge

[Ndrinta]

Hi Nathan,
Yesterday I was looking at the Charge Needed sensor and I happily noticed that was indicating '0', now, my comprehension of this is that no charge is needed overnight during off-peak.
I noticed I had a spike tonight though, just a 10 minutes spike at precisely 00:30.

Is this a know issue or just physiological to your algorithm or shall we look into it?
Cheers.

Forgot to mention: the MaxChargeCurrent is set to 10A in my system, working out to ~2.1kW that we see here.

[nathanmarlor]

Thanks for raising. At first guess:

#1 - it refreshed the forecast and subsequently the battery model at 00:25 (5 mins before off-peak starts) and decided a small top up was needed.

#2 - it tried to cancel your charge at 00:30 but Fox Cloud wasn't responding and it took 10 mins of retries to succeed.

Can you include more logs/relevant data points please?

Nathan

[Ndrinta]

By looking at the pic below seems like we can exclude n.1

For n.2, I'll try with these settings tonight (I've disabled the "Enable force charge from grid" switch, previously enabled). With some luck I won't need any top up tonight and we can test your theory.

(In terms of log) What would you be interested in? Happy to share.

[nathanmarlor]

That makes things easier then :)

Any errors contacting Fox Cloud would be logged under Settings -> System -> Logs.

The integration will reset your Fox Cloud settings 5 minutes before the off-peak period begins, so those settings will be overwritten. Tbf there probably isn't a need for a 'pre off-peak' and 'off-peak' event since moving to an always on model. If a charge isn't required the charge windows could be cleared in the 'pre off-peak' event.

[Ndrinta]

Hi, unfortunately I've experienced a fault tonight.
I lost communication through Modbus (LAN) at around 00:43 (just a little over 10 minutes after the beginning of the off-peak period).

The inverter then proceeded charging the battery at full beans after a temporary stop, probably an inverter restart (?).

I woke up with a full battery, even if the necessary charge was 0 ("Capacity: Charge Needed" was 0, I double checked).

Also, I cannot establish Modbus communications anymore. I tried restarting Inverter, Router and HA.
I tried enabling DHCP again, just to check if inverter could still get an IP and it does no problems.
I'm in version 1.48, 1.02, 1.50 so no problems with the LAN Modbus. Well, so far...

Did you ever experience something like this?

Needless to say that I'm going to disable your integration for the now, at least until I understand what's going on here.

[nathanmarlor]

That's very odd. My modbus integration has been really stable - never had any issues. Are you using the W610 or something else?

Btw it seems Fox Cloud communicates to the inverter via Modbus over TCP (ish). If the modbus server faulted it's not surprising it was uncontactable, hence the full charge.

Fyi I reversed the logic on this recently, it used to start with no charge windows set and only enable them if needed. However we were finding the Fox Cloud to be so unstable that people were often waking up with empty batteries, hence the more 'fail safe' approach.

Hope you get it sorted soon.

[Ndrinta]

No, Router to Ethernet port on the inverter.
I've downloaded the log and restored a previous snapshot and I was back up
and running in no time but I haven't yet got the chance to thoroughly
explore the log.
From a quick overview I noticed it started throwing a long chain of "Host
unreachable" on Modbus at roughly 00.30, not surprisingly.

I just can't afford being "offline" tomorrow so I'm going to enable the
integration again only tomorrow (the day after tomorrow) afternoon.

I kinda hope it happens again, I want to know what we are dealing with
here...

[Ndrinta]

Well, this happened... (time period 00:25 to 04:35)

I believe the charge was ~constant throughout the charging period (looking at the FoxESS cloud data) but the inverter manager kept resetting (as I mentioned I use a straight LAN connection, router to inverter).

There was a HA restart at 00:19, that coincides with the lost of data in the first graph.
It restarted smoothly and the first error I can find for this Integration was:
2023-02-23 00:27:30.186 ERROR (MainThread) [custom_components.foxess_em.fox.fox_cloud_service] Could not make request to Fox Cloud - Error: 40257
followed by:
2023-02-23 04:32:12.508 ERROR (MainThread) [custom_components.foxess_em.fox.fox_cloud_service] Fox Cloud API error:
and
2023-02-23 04:32:23.207 ERROR (MainThread) [custom_components.foxess_em.fox.fox_cloud_service] Could not make request to Fox Cloud - Error: 40257

I can't find anything regarding solcast although something was off there too:

The API key that the integration has access to is a 50 calls one.
I also have a secondary Solcast Integration that uses a different API key, that one works flawlessly.

At this point a wonder what the differences are between our systems.
Do you connect to the Inverter in a different manner? What is your manager version?
What would you want me to try differently, as I said I'm happy to test, I believe this integration has an enormous potential and I don't want to give up yet.

For the records, I currently run on:
Master : 1.54
Slave : 1.02
Manager : 1.50

Also, to prove all is good with my system, here is the early hours of the 22nd ("the night before")

The settings for this charging session were set manually by me:
Time period 1: 00:30 to 03:30 - Force charge only
Time period 2: 03:30 to 04:30 - Force charge from grid

EDIT:
This morning (08:37) there was a uncorrelated restart (due to a loss of grid power in the neighborhood) so HA restarted again. In the new log I found a Solcast error

2023-02-23 08:44:20.302 ERROR (MainThread) [custom_components.foxess_em.forecast] Solcast API fetch error:

Since then, no new Solcast requests were made by the integration. But I'm sure you will believe me when I say this has been an ongoing issue:

[nathanmarlor]

The latest EM update includes a change for manager version 1.57 as the API call to set maximum discharge changed. I noticed this as I was seeing error 40257 too, which is basically an invalid request. I think you can safely ignore this, and I'll find a way of ensuring it works across all manager versions at some point in the future.

The more concerning aspect is why your connection to Solcast is dropping out, and why you're losing data from the Modbus connection (and/or causing the inverter to restart). I swapped back to the 485 setup recently as I wanted to keep manager up to date - I don't see any drop outs or odd behaviour with this.

Do you lose connection at any other time, or is it just during the charge periods? Do you have any other networking components setup - pihole etc.? Also restarting HA during a charge period isn't recommended, as it loses state and will revert back to the 'fail safe' of a forced charge; if you're using watchtower or other it's best to schedule updates outside of your charge window.

[Ndrinta]

Ok, so we can list comm method as a difference.
The weird behaviour with Solecast puzzles me too. I used that 50-calls API key for the past 2 years or so without a problem, then I applied for a new one (unfortunately 10-calls only) to give the "good one" to your integration a couple days ago.

The 10-calls one has no problems as you can see (the drops you can see here and there are when I tried to Disable the pure Solcast integration after seeing EM was reporting 'Unknown', I thought that maybe the Solcast server was throttling/blacklisting my IP).

I extremely rarely lose connection when EM is disabled (I think I lost communication a few times at a few months ago when I got my system installed, then turned out to be DHCP issues which I then fixed using Static IP and, a part from that, I honestly don't remember the last time that a random drop happened, it's been pretty stable).
About my setup, I run a super simple ASUS router which generally has no problems when this integration is disabled.

I did not restart HA during the charging period on purpose, nor any planned update did it.
I believe this happened at exactly 00:20 ±1min 3 times so far, those night when the EM integration was Enabled and "Disable Auto Charge" switch was OFF.

I probably run some sort of maintenance or backup over the period 00:00 - 05:00 thay may interfere with EM.
I'll report shortly.

[Ndrinta]

I found 2 potential interfering tasks:

• Home Assistant Google Drive Backup was running the daily backup at 02:30 -> Now moved at 05:30.
• VM Virtual Box Manager is taking a weekly Snapshot of the VM at 03:30 - Because it hasn't run during any of the analysed days, I will retain this schedule for the time being.

[Ndrinta]

Hi Nathan, I think I have found a clue.
After some time testing my scripts I decided to have a go with 1.6.3 (after upgrading to 1.57 a bunch of days ago).
It restarted (crashed) HA a couple time again and I finally noticed a potential cause:

At around 9:05AM I enabled the automation this morning to start debugging and after about 30 min I experienced a new HA crash. At 9:40, after the restart I disabled the EM Integration again, and you can notice the little ramp stopping and settling again to the 55% mark. Looking at the log I can't see anything about EM this time.

And, yes, I excluded the raw data from the logger. Is there anything else I should exclude?

recorder:
  db_url: mysql://xxx:xxx@core-mariadb/homeassistant?charset=utf8mb4
#  db_url: sqlite:////media/hassio_db/home-assistant_v2.db
  purge_keep_days: 28
  exclude:
    entities:
      - sensor.foxess_em_raw_data

[nathanmarlor]

@Ndrinta are you still experiencing issues or can this be closed?

[Ndrinta]

Never worked properly for me so I abandoned this about 2 weeks after these first issues.
Might not be the case now and might give it another go in the future but for now I'm happy with my custom automations right now.
Cheers for caring.