Enphase Envoy often shows I send more energy to the grid than I produce from Enphase Envoy about core

[wptracy]

I'm still seeing the behavior of reporting more power back to the grid than I produce, but It's not nearly as bad as it was before I matched and synchronized the polling interval time (15 minutes) for Grid Power and Envoy Power..

So I should close this ticket.

@catsmanac , thanks for you help in analyzing and fixing this.

It looks like Envoy was overwhelmed with all the polling and couldn't keep up with 5 second polling of 21 panels.

Smart Electric Meter Power and Envoy Current power production still get out of sync, but not like it was before when I saw double the power back to the grid than Envoy produced.

[home-assistant]

Hey there @bdraco, @cgarwood, @dgomes, @joostlek, @catsmanac, mind taking a look at this issue as it has been labeled with an integration (enphase_envoy) you are listed as a code owner for? Thanks!

Code owner commands

Code owners of enphase_envoy can trigger bot actions by commenting:

• @home-assistant close Closes the issue.
• @home-assistant rename Awesome new title Renames the issue.
• @home-assistant reopen Reopen the issue.
• @home-assistant unassign enphase_envoy Removes the current integration label and assignees on the issue, add the integration domain after the command.
• @home-assistant add-label needs-more-information Add a label (needs-more-information, problem in dependency, problem in custom component) to the issue.
• @home-assistant remove-label needs-more-information Remove a label (needs-more-information, problem in dependency, problem in custom component) on the issue.

_{^{(message by CodeOwnersMention)}}

---

enphase_envoy documentation
enphase_envoy source
_{^{(message by IssueLinks)}}

[catsmanac]

Hi @wptracy, have you checked what Envoy response times are when using the standard 60 sec interval? Enable debug on the HA enphase_envoy integration, let it run for some time. Check log file for lines with finished fetching Envoy

Finished fetching Envoy 123456789012 data in 1.234 seconds (success: True)

That will provide you with some background on how long all responses take. You can also see time it takes to get individual data endpoints from the Envoy in this way.

2024-05-29 11:33:37.283 DEBUG (MainThread) [pyenphase.envoy] Requesting https://192.168.1.10/production.json?details=1 with timeout Timeout(connect=10.0, read=45.0, write=10.0, pool=10.0)
2024-05-29 11:33:37.771 DEBUG (MainThread) [pyenphase.envoy] Request reply from https://192.168.1.10/production.json?details=1 status 200: 

Then do same with custom interval of 30 sec first or 10 sec again and see how this goes. The debug log will provide more details on what is going on.

[wptracy]

I couldn't include the debug log because maximum comment size is 65536 characters.
so I grep'ed "Finished"instead.

The debug log below has 3 different captures (time 03:47, time 15:43, and time 07:42):
The 1st two captures had a trigger time set for 10 seconds over a 1 minute period of time. Maximum Finish time of 3.779 seconds
The last capture had a trigger time of 60 seconds over a 6 minute period of time. Maximum Finish time of 4.275 seconds

I grep'ed the debug file for "envoy" to get just the envoy logs:

Enphase Envoy fetches production.json?details=1, production/inverters, and admin/lib/tariff
Then the inverter readings roll in.

The longest it took to fetch the data was 4.275 seconds.

So it should be able to fetch all the data in 10 seconds.

DEBUG LOG:

wptracy@Rpi5-1-logitechmediaserver:~/Downloads $ grep Finished 'comment back to Arie Catsman.txt'
2024-06-17 03:47:27.793 DEBUG (MainThread) [homeassistant.components.enphase_envoy.coordinator] Finished fetching Envoy 202321168106 data in 1.657 seconds (success: True)
2024-06-17 03:47:41.002 DEBUG (MainThread) [homeassistant.components.enphase_envoy.coordinator] Finished fetching Envoy 202321168106 data in 3.205 seconds (success: True)
2024-06-17 03:47:53.528 DEBUG (MainThread) [homeassistant.components.enphase_envoy.coordinator] Finished fetching Envoy 202321168106 data in 2.518 seconds (success: True)
2024-06-17 03:48:06.459 DEBUG (MainThread) [homeassistant.components.enphase_envoy.coordinator] Finished fetching Envoy 202321168106 data in 2.924 seconds (success: True)
2024-06-17 03:48:17.716 DEBUG (MainThread) [homeassistant.components.enphase_envoy.coordinator] Finished fetching Envoy 202321168106 data in 1.252 seconds (success: True)
2024-06-17 03:48:29.517 DEBUG (MainThread) [homeassistant.components.enphase_envoy.coordinator] Finished fetching Envoy 202321168106 data in 1.794 seconds (success: True)
2024-06-17 15:43:56.294 DEBUG (MainThread) [homeassistant.components.enphase_envoy.coordinator] Finished fetching Envoy 202321168106 data in 2.733 seconds (success: True)
2024-06-17 15:44:10.084 DEBUG (MainThread) [homeassistant.components.enphase_envoy.coordinator] Finished fetching Envoy 202321168106 data in 3.779 seconds (success: True)
2024-06-17 15:44:23.517 DEBUG (MainThread) [homeassistant.components.enphase_envoy.coordinator] Finished fetching Envoy 202321168106 data in 3.426 seconds (success: True)
2024-06-17 15:44:34.702 DEBUG (MainThread) [homeassistant.components.enphase_envoy.coordinator] Finished fetching Envoy 202321168106 data in 1.175 seconds (success: True)
2024-06-17 15:44:46.734 DEBUG (MainThread) [homeassistant.components.enphase_envoy.coordinator] Finished fetching Envoy 202321168106 data in 2.024 seconds (success: True)
2024-06-18 07:42:00.671 DEBUG (MainThread) [homeassistant.components.enphase_envoy.coordinator] Finished fetching Envoy 202321168106 data in 1.567 seconds (success: True)
2024-06-18 07:43:01.869 DEBUG (MainThread) [homeassistant.components.enphase_envoy.coordinator] Finished fetching Envoy 202321168106 data in 2.764 seconds (success: True)
2024-06-18 07:44:03.379 DEBUG (MainThread) [homeassistant.components.enphase_envoy.coordinator] Finished fetching Envoy 202321168106 data in 4.275 seconds (success: True)
2024-06-18 07:45:00.937 DEBUG (MainThread) [homeassistant.components.enphase_envoy.coordinator] Finished fetching Envoy 202321168106 data in 1.835 seconds (success: True)
2024-06-18 07:46:01.060 DEBUG (MainThread) [homeassistant.components.enphase_envoy.coordinator] Finished fetching Envoy 202321168106 data in 1.958 seconds (success: True)
2024-06-18 07:47:02.995 DEBUG (MainThread) [homeassistant.components.enphase_envoy.coordinator] Finished fetching Envoy 202321168106 data in 3.893 seconds (success: True)
wptracy@Rpi5-1-logitechmediaserver:~/Downloads $ 

[catsmanac]

I couldn't include the debug log because maximum comment size is 65536 characters.

You can upload the file by dragging it onto below the comment box.

The examples you shared shows a completion ~every 12-14 sec for the 10 sec cycle and every 60-63 sec in the 60 sec cycle.

Next step would be to check the debug to see what values for current_power_production are in the log file. If the value doesn't change between 2 readings HA history is probably not storing it.

[wptracy]

I'm not a unix or perl shell scripter. It would take me forever to parse and add up all the inverter readings.

Are you expert in scripting??

The problem was happening between 10:35 and 1:45 AM. I had debug turned on and am uploading the debug file.
In one of the screenshots, There is a big difference between what enphase produced (2,880 Watts) and what was fed back to the grid (-5472 Watts).

The "last_report_watts=" do change, but not by much, I don't know if they add up to the total reported by Enphase Envoy App.

I'm including some screenshots of the problem and also a readable file format of https://10.0.0.105/api/v1/production/inverters

[
  {
    "serialNumber": "202331145751",
    "lastReportDate": 1718728822,
    "devType": 1,
    "lastReportWatts": 213,
    "maxReportWatts": 329
  },
  {
    "serialNumber": "202331145858",
    "lastReportDate": 1718728823,
    "devType": 1,
    "lastReportWatts": 214,
    "maxReportWatts": 329
  },
  {
    "serialNumber": "202331146991",
    "lastReportDate": 1718728852,
    "devType": 1,
    "lastReportWatts": 226,
    "maxReportWatts": 329
  },
  {
    "serialNumber": "202331149166",
    "lastReportDate": 1718728762,
    "devType": 1,
    "lastReportWatts": 183,
    "maxReportWatts": 329
  },
  {
    "serialNumber": "202331151170",
    "lastReportDate": 1718728853,
    "devType": 1,
    "lastReportWatts": 229,
    "maxReportWatts": 329
  },
  {
    "serialNumber": "202331153017",
    "lastReportDate": 1718728763,
    "devType": 1,
    "lastReportWatts": 183,
    "maxReportWatts": 329
  },
  {
    "serialNumber": "202331153959",
    "lastReportDate": 1718728854,
    "devType": 1,
    "lastReportWatts": 230,
    "maxReportWatts": 329
  },
  {
    "serialNumber": "202331154288",
    "lastReportDate": 1718728942,
    "devType": 1,
    "lastReportWatts": 203,
    "maxReportWatts": 329
  },
  {
    "serialNumber": "202331154526",
    "lastReportDate": 1718728792,
    "devType": 1,
    "lastReportWatts": 197,
    "maxReportWatts": 329
  },
  {
    "serialNumber": "202331155409",
    "lastReportDate": 1718728763,
    "devType": 1,
    "lastReportWatts": 185,
    "maxReportWatts": 330
  },
  {
    "serialNumber": "202331156456",
    "lastReportDate": 1718728793,
    "devType": 1,
    "lastReportWatts": 199,
    "maxReportWatts": 329
  },
  {
    "serialNumber": "202331157995",
    "lastReportDate": 1718728793,
    "devType": 1,
    "lastReportWatts": 201,
    "maxReportWatts": 329
  },
  {
    "serialNumber": "202331158076",
    "lastReportDate": 1718728855,
    "devType": 1,
    "lastReportWatts": 162,
    "maxReportWatts": 329
  },
  {
    "serialNumber": "202331158772",
    "lastReportDate": 1718728855,
    "devType": 1,
    "lastReportWatts": 233,
    "maxReportWatts": 329
  },
  {
    "serialNumber": "202331159864",
    "lastReportDate": 1718728823,
    "devType": 1,
    "lastReportWatts": 214,
    "maxReportWatts": 329
  },
  {
    "serialNumber": "202331159881",
    "lastReportDate": 1718728824,
    "devType": 1,
    "lastReportWatts": 217,
    "maxReportWatts": 329
  },
  {
    "serialNumber": "202331159895",
    "lastReportDate": 1718728856,
    "devType": 1,
    "lastReportWatts": 232,
    "maxReportWatts": 329
  },
  {
    "serialNumber": "202213129654",
    "lastReportDate": 1718728972,
    "devType": 1,
    "lastReportWatts": 213,
    "maxReportWatts": 329
  },
  {
    "serialNumber": "202224144296",
    "lastReportDate": 1718728882,
    "devType": 1,
    "lastReportWatts": 179,
    "maxReportWatts": 329
  },
  {
    "serialNumber": "202224158329",
    "lastReportDate": 1718728912,
    "devType": 1,
    "lastReportWatts": 186,
    "maxReportWatts": 329
  },
  {
    "serialNumber": "202224161713",
    "lastReportDate": 1718728943,
    "devType": 1,
    "lastReportWatts": 207,
    "maxReportWatts": 329
  }
]

1035to1045.txt

[catsmanac]

If you can upload the debug file as file then I'll have a look at the raw data with a script I'm working on for something different already.

[wptracy]

1035to1045.txt

[catsmanac]

Looking at the data in 1035to1045.txt you can see that the trigger fires 10 seconds after a data request completes.

2024-06-18 10:30:10.650 DEBUG (MainThread) [homeassistant.components.enphase_envoy.coordinator] Finished fetching Envoy 202321168106 data in 1.945 seconds

2024-06-18 10:30:20.654 DEBUG (MainThread) [pyenphase.envoy] Requesting https://10.0.0.105/production.json?details=1 with timeout Timeout(connect=10.0, re
2024-06-18 10:30:22.100 DEBUG (MainThread) [homeassistant.components.enphase_envoy.coordinator] Finished fetching Envoy 202321168106 data in 1.446 seconds

2024-06-18 10:30:32.114 DEBUG (MainThread) [pyenphase.envoy] Requesting https://10.0.0.105/production.json?details=1 with timeout Timeout(connect=10.0, re
2024-06-18 10:30:35.169 DEBUG (MainThread) [homeassistant.components.enphase_envoy.coordinator] Finished fetching Envoy 202321168106 data in 3.056 seconds

2024-06-18 10:30:45.179 DEBUG (MainThread) [pyenphase.envoy] Requesting https://10.0.0.105/production.json?details=1 with timeout Timeout(connect=10.0, re
2024-06-18 10:30:47.427 DEBUG (MainThread) [homeassistant.components.enphase_envoy.coordinator] Finished fetching Envoy 202321168106 data in 2.248 seconds

2024-06-18 10:30:57.435 DEBUG (MainThread) [pyenphase.envoy] Requesting https://10.0.0.105/production.json?details=1 with timeout Timeout(connect=10.0, re
2024-06-18 10:30:58.634 DEBUG (MainThread) [homeassistant.components.enphase_envoy.coordinator] Finished fetching Envoy 202321168106 data in 1.200 seconds

2024-06-18 10:31:08.645 DEBUG (MainThread) [pyenphase.envoy] Requesting https://10.0.0.105/production.json?details=1 with timeout Timeout(connect=10.0, re

Then at 10:34 there's triggers for collection during 2 minutes 20 sec.

2024-06-18 10:34:12.244 DEBUG (MainThread) [homeassistant.components.enphase_envoy.coordinator] Finished fetching Envoy 202321168106 data in 1.568 seconds (success: True)

2024-06-18 10:36:31.264 DEBUG (MainThread) [pyenphase.envoy] Requesting https://10.0.0.105/production.json?details=1 with timeout Timeout(connect=10.0, read=45.0, write=10.0, pool=10.0)

After which the 10 sec after each collection end trigger resumes. Envoy replies in 3-4 sec each time when data collection occurs, but trigger does not seem to occur. From Envoy side I can't see why. To detect issues around the triggers you can opt to enable full debug on HA by adding

homeassistant:
  debug: true

to your configuration.yaml and restart HA. That will grow the log file, so depending on how frequently the issue occurs it might become quite large.

What type Envoy do you have, metered without current transformers or Standard (not metered) one?

Still looking into the other data details. Power values will always be time dependent, In above case the solar was frozen for 2 minutes. Have to validate it, but I think the Envoy, without Current Transformers is only updating it's data from the inverters 1/minute.

[wptracy]

To detect issues around the triggers you can opt to enable full debug on HA by adding

homeassistant:
  debug: true

I can't get this debug mode this to work. It says Property debug is not allowed in homeassistant:

homeassistant:
debug: true Property debug is not allowed.

[catsmanac]

Strange, got directions to look here for this and I think you are running 2024.6.x which is newer as the 2024.5.x required.

Alternative to try would be:

logger:
  default: debug

[wptracy]

logger:
default: debug

This enables debug logging everywhere, but the logs don't show up in logs.

[catsmanac]

I combined the data in the debug log into and overview for Power/Watts reported from various sources. File is attached below. The top row is the header row:

header	description
scan end	the time when the log reported Finished fetching Envoy xxx data in yyy seconds which is the end of the data collection cycle from the envoy
duration	The time it took to collect the data as reported in the log line
interval	Seconds between the collection end and the previous end. Should reflect how often the trigger fires.
sum inv W prod	The sum of the Power reported by the individual inverters.
inv W	The reported total inverter Power in the inverter segment of the /production endpoint
prod W	The reported produced Power in the production segment of the /production endpoint
inverter time	The time in the day when the individual inverter report was received
inverter time span	Each inverter in the individual inverter report reports a 'last reported to envoy' time. The time span is the oldest and the most recent time of these times.
pr.inv time	The reading time of the inverter section of the /production endpoint
prod time	The reading time of the production section of the /production endpoint

Last 3 time columns have my local timezone time, that's caused by the data processing.

1035to1045_watts.txt

• The duration column shows that in most cases the Envoy responds withing 5 seconds. There's one case of 10 seconds and one of 7 seconds.
• The intervals are mostly 12-13 seconds, with one case of 140 seconds, the known failure moment and one of 20. The last one caused by the previous 10 second reply.
• As the /production report shows the CT are not active, the source of the production data is the inverter section, the inv W column instead of the prod W column. Comparing the inv W column to the sum inv W prod show that these are really close.
• When looking at the values in these columns one can note that the same value may show up in 2 or even 3 subsequent scans. This also the case in the timestamp columns.
  

This does not explain anything about the 2 minute gap, aside from the fact that for some reason data collection did not trigger as there are no data collections in the log in that period.

If shows however that your trigger frequency is faster as the Envoy updates from the inverters. That is not an issue on it's own, but explains why you won't see data every 10 seconds in HA history as these are only recorded when values change. And it will cause these out-of-sync values with the grid meters.

Still need to look at the energy side of this.

[catsmanac]

This enables debug logging everywhere, but the logs don't show up in logs.

Nothing in the home-assistant.log file in the config folder?

[wptracy]

If shows however that your trigger frequency is faster as the Envoy updates from the inverters.

I increased the trigger to 15 seconds.

I'm experiencing the same problem, I'm sending more power to the grid than I produce.

I enabled debug again and grep'ed the log for envoy.

I'm uploading both logs, the all_logs and the grep'ed logs so we can maybe correlate some other event with the start of the long interval of no collection.

That script you made is very impressive. I like the report it generates. Thanks!! And thanks for your help on this.

I included screenshots of the energy meters for the same time period. File names have the timestamps.

grep_debug_log_for_envoy.txt
all_debug_logs_home-assistant_enphase_envoy_2024-06-19T19-11-58.498Z.log

[wptracy]

This enables debug logging everywhere, but the logs don't show up in logs.

Nothing in the home-assistant.log file in the config folder?

When I enable and disable debug on the enphase envoy integration it takes a snapshot of /root/config/home-assistant.log and downloads it to my windows directory from firefox.

I don't see any difference in debug level when I make the log debug entry in configuration.yaml

[catsmanac]

I don't see any difference in debug level when I make the log debug entry in configuration.yaml

The difference is that when using the configuration.yaml method, debug is enabled for all modules in Home Assistant. We are looking for something outside enphase that happens when the triggers you configured fail to start the data collection and cause the 2 minute gap. Something that maybe prevents the triggers from firing or anything else. These triggers are not part of the Envoy code but rather HA functionality.

[catsmanac]

I'm experiencing the same problem, I'm sending more power to the grid than I produce.

The fundamental issue is that the envoy reports Power/Watts collected only every 20-30 sec from the inverters and the smart electric meter is reporting every 5 seconds. So these will very often differ as these are not in sync. Only if these are taken really close together it will be close. No matter how you set the trigger, this will remain with this configuration.

Below is my Envoy showing the same, the purple line being the grid export on various occasions more then the green envoy production line. Data not taken at exact same time at both measurement points is causing this, especially when variations in power usage or production occur.

To have a sensor that shows what is going on in the course of the day, outside of the energy dashboard, you can configure a daily utility meter helper using Envoy <serial> Lifetime Energy production, one for the 'smart electric meter production' and the 'smart electric meter consumption'. You will see these growing during the day and reset to zero at midnight. This provides a more accurate view on what is going on, but is not a momentary view of what happens at that exact moment, but rather how energy evoved over the day.

[wptracy]

I have this saved in configuration.yaml and I restarted, but now it's not enabeloing debug on all modules.

logger:
default: debug

[wptracy]

Only if these are taken really close together it will be close. No matter how you set the trigger, this will remain with this configuration.

So if I set the automation to trigger every 15 seconds, and Smart Electric Meter Production and Consumption to poll every 15 seconds this should work?

I'll do the polling every 15 seconds and see if that works.

[catsmanac]

So if I set the automation to trigger every 15 seconds, and Smart Electric Meter Production and Consumption to poll every 15 seconds this should work?

Doubt it as there's delay between the Envoy and it's inverters, but trying will learn it.

[wptracy]

how do you do the helper for "Envoy Lifetime Energy production"

[catsmanac]

Go to Setting / Devices & Services / Helpers. Use create helper and select utility meter from the list. input sensor would be the sensor.envoy_<sn>_lifetime_energy_production. Select Daily for meter reset cycle.

[catsmanac]

I have this saved in configuration.yaml and I restarted, but now it's not enabeloing debug on all modules.

Not sure if it always shows on the dashboard. See Settings / System / Logs and use button there to download or to view the log file.

[wptracy]

Go to Setting / Devices & Services / Helpers.

I created the helper, now how do I display it like yours.

[catsmanac]

That's a history-graph card

  - type: history-graph
    entities:
      - entity: sensor.envoy_no_dagproductie
      - entity: sensor.envoy_zw_dagproductie
      - entity: sensor.electriciteit_balans
    hours_to_show: 36

I use 2, top one for energy and bottom one for power.

The top one has the daily energy utility meters.
The bottom power one has power production from envoy and production and consumption from my smart meter.

[wptracy]

I created the power consumption and production. I think I have to wait and see what it looks like in 36 hours.

How did you create the sensors for Envoy NO and ZW Daily Production and Electricity Balance?
What is NO and ZW

[catsmanac]

Ah, NO and ZW is Dutch for NE (North-East) and SW (South West). I have half of my panels facing North-East and half of them South-West.

I have a Riemann Integrator helper on each panel, this helper integrates the power into lifetime energy for each panel. And on each panel's lifetime energy I have a daily utility meter so I know daily energy produced per panel.

NO Daily production is then the sum of the daily utility meters NE facing and ZW Daily Production the sum for the SW facing panels.

Electricity balance is the sum of 2 daily utility meters, one on my smart meter lifetime grid energy import and one on my smart meter lifetime grid energy export. So it shows my daily balance for import vs export. As the smart meter is the one also read (and owned) by the electricity company it what really counts.

[wptracy]

Thanks @catsmanac

Yesterday I configured the automation to poll Envoy every 15 minutes and the configuration.yaml smart.electric.meter.power/consumption/production to poll every 15 minutes. I synchronized them with a restart and yesterday the meter readings looked believable. I'm watching it again today.

My Utility Meter helper and history-graph card isn't looking like your. Either I have the wrong sensors assigned or I'm doing something else wrong.

  - type: history-graph
    entities:
      - entity: sensor.power_consumption
      - entity: sensor.power_production
      - entity: sensor.envoy_production_kw
    hours_to_show: 36

For the other issue I opened a ticket on, I'm waiting to see if I get a consumption or production spike when envoy lifetime reaches roughly 1.2MWh.

[catsmanac]

Your history card is nicely revealing what is going on, consumption from midnight going up, then it starts flattening a bit when solar gets going. And next you will see power_production going up when solar exceeds house demand.

I have an addinitional calculation on grid production and consumption, in your case something like:

 - name: "Electricity Balance"
    unique_id: Electricity_balance_kWh
    unit_of_measurement: "kWh"
    icon: mdi:solar-panel
    state: >
      {{(states('sensor.power_production') | float(0)
        - states('sensor.power_consumption') | float(0)) | round(3) }}
    availability: >
      {{ has_value('sensor.power_production') and
         has_value('sensor.power_consumption') }}