briancmpbll / home_assistant_custom_envoy

173 stars 76 forks source link

Legacy Envoy stopped working in versions 0.0.12 & 0.0.13 #115

Closed madbrain76 closed 10 months ago

madbrain76 commented 1 year ago

Using an Envoy LCD (Envoy-R) I had to revert back to 0.0.11 to get it to work again. There is a regression in 0.0.12 that broke the legacy Envoy.

Note that also have an IQ Envoy in addition, but I don't think it matters. The IQ Envoy still works in versions 0.0.12/0.0.13 .

catsmanac commented 1 year ago

Any information in the log file that can share where it broke?

madbrain76 commented 12 months ago

Screenshot_20230720_135440_Home Assistant

madbrain76 commented 12 months ago

This error originated from a custom integration.

Logger: custom_components.enphase_envoy Source: custom_components/enphase_envoy/envoy_reader.py:401 Integration: Enphase Envoy (DEV) First occurred: 14:04:38 (5 occurrences) Last logged: 14:06:01

Unexpected error fetching envoy Envoy 121023267212 data: 'NoneType' object has no attribute 'text' Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 283, in _async_refresh self.data = await self._async_update_data() ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 242, in _async_update_data return await self.update_method() ^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/config/custom_components/enphase_envoy/init.py", line 50, in async_update_data await envoy_reader.getData() File "/config/custom_components/enphase_envoy/envoy_reader.py", line 401, in getData response.text, ^^^^^^^^^^^^^ AttributeError: 'NoneType' object has no attribute 'text'

catsmanac commented 12 months ago

That error in 0.0.12 is caused by a debug statement trying to print what it received. If it didn't receive anything that error will happen. The debug statement is still present on 0.0.13 but already removed in Main. So you may want to try Main to verify if that works.

madbrain76 commented 12 months ago

How do I try main ? I only see numbered releases in HACS.

catsmanac commented 12 months ago

In HACS Select the custom integration. It will open the details screen. Then use the 3 vertical dot menu at the top right and select 'download again'. Use the pull down on the right of the version to select a version to download. Optionally flip the 'allow beta versions' switch to see those too, if there are any. Main version is probably at the bottom of the list.

afbeelding

madbrain76 commented 12 months ago

Thanks. I updated to main, but it still doesn't work with the legacy Envoy-R LCD. Here is the log.

This error originated from a custom integration.

Logger: custom_components.enphase_envoy Source: custom_components/enphase_envoy/envoy_reader.py:399 Integration: Enphase Envoy (DEV) First occurred: 12:07:31 (3 occurrences) Last logged: 12:07:52

Unexpected error fetching envoy Envoy 121023267212 data: 'NoneType' object has no attribute 'status_code' Traceback (most recent call last): File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 283, in _async_refresh self.data = await self._async_update_data() ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 242, in _async_update_data return await self.update_method() ^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/config/custom_components/enphase_envoy/init.py", line 50, in async_update_data await envoy_reader.getData() File "/config/custom_components/enphase_envoy/envoy_reader.py", line 399, in getData if response.status_code == 401: ^^^^^^^^^^^^^^^^^^^^ AttributeError: 'NoneType' object has no attribute 'status_code'

catsmanac commented 12 months ago

Can you run with debug enabled for a couple of minutes? Enable debug on the Envoy and let it run for a couple of minutes. Then disable debug again. Then it will download the log file to your pc. That will add details of what pages are failing.

afbeelding (Dutch for enable debug)

madbrain76 commented 12 months ago

The legacy envoy doesn't have a debug option. It's really completely different from the IQ Envoy. This is what it looks like right now.

image

This root page is not protected by any kind of authentication. It's plaintext HTTP also. This is the only one that the integration needs to access.

(ignore the facts all 40 micros are down, someone is on the roof switching some 12panels/micros right now. That's not the root cause of the problem; the 0.0.11 integration and below just shows 0 watt properly in this situation).

catsmanac commented 12 months ago

Thanks for the explanation. By enable debug I actually meant debug in Home assistant, not on the legacy envoy itself.

So for some reason the new version now hits a page that is not available on the old one and it didn't before. If you can generate that log file that would help in tracing the what it is doing.

madbrain76 commented 12 months ago

Sorry, I got confused by the Dutch language and the color scheme which seemed to match Enphase's and not HA.

I enabled debug logging in the Enphase Dev 0.0.13 integration. Where is the log file located ?

catsmanac commented 12 months ago

It is trying to get inverter data at the spot in the error. As you explained, that information is not available on the old type. Next question is why it started doing that in the newer versions.

catsmanac commented 12 months ago

Sorry, I got confused by the Dutch language and the color scheme which seemed to match Enphase's and not HA.

I enabled debug logging in the Enphase Dev 0.0.13 integration. Where is the log file located ?

In the config folder named home-assistant.log, where the configuration.yaml is too. Otherwise, just disable the debug again and HA will download the file to your pc.

madbrain76 commented 12 months ago

Here is a log with the 0.0.13 integration (failure case).

home-assistant_2023-07-21T19-51-20.876Z.log

madbrain76 commented 12 months ago

Here is a log with the 0.0.11 integration (success case).

home-assistant_2023-07-21T19-56-28.356Z.log

catsmanac commented 12 months ago

I see 2devices, one at 192.168.100.12, legacy envoy and one at 192.168.100.133, Modern Envoy? The 12 is getting status 404 on the inverters page and generates the error. The other one seems to be working ok.

catsmanac commented 12 months ago

Found the issue, with the introduction of the 3 phase sensors (0.0.12) the code was changed and as result the function to read the envoy now returns None (Nothing) where before it would return the status 404. Since None is returned next code fails where in the older version it could chew on the 404 status.

Interestingly though, there is logic to not collect the individual inverters data, but no logic to trigger it based on a legacy model.

This needs to be changed, that's next step and daylight is running out here now.

@posixx the autodetect for the 3 phase change now returns None when a 404 is detected by fetch_with_retry. Getdata function defaults to getting inverter data that would return the 404 status in the past, but now gets a None back from fetch_with_retry. Fundamental question is why it tries to get inverters in the first place.

madbrain76 commented 12 months ago

Glad you found the issue ! There is no inverters page on the legacy Envoy, AFAIK. And you got my devices right, the Legacy envoy at .12 and the IQ at .133 . I don't think it's possible to get inverter data from the legacy Envoy. Is it possible it's confusing the models ?

catsmanac commented 12 months ago

The code change has been made and PR #116 was requested. I can not merge the change into main myself. @briancmpbll or @posixx can you help?

The 2 envoy's in your log where dealt with separately as it should. The changed code will no longer get the inverters for the legacy model and the error should not get back.

Turned out it was a simple change of 1 file. If you can access your files in /config/custom_components/enphase_envoy and feel like it, you can change envoy_reader.py in there after you installed 0.0.13 again. Go to line 463

            self.endpoint_type = ENVOY_MODEL_LEGACY  # older Envoy-C
            return

and insert a new line after 463 like below

            self.endpoint_type = ENVOY_MODEL_LEGACY  # older Envoy-C
            self.get_inverters = False # don't get inverters for this model
            return

I could not test the new code for this specifically as I have a newer Envoy. Tested it with that one but obviously no proof yet for your case.

posixx commented 12 months ago

I have merged the change. @madbrain76 please update integration from main and let us know if it solves your problem. If it does; please close this issue.

DMedina559 commented 12 months ago

I'm still having issues with my Envoy-R with the main branch, but mine also doesn't work with any of the older branches either. Is there anything I need to clear out first?

madbrain76 commented 12 months ago

Unfortunately, the main branch does not work for me. Here is the error I see for my Envoy-R.

This error originated from a custom integration.

Logger: custom_components.enphase_envoy
Source: custom_components/enphase_envoy/envoy_reader.py:584
Integration: Enphase Envoy (DEV)
First occurred: 14:27:01 (5 occurrences)
Last logged: 14:28:25

Unexpected error fetching envoy Envoy 121023267212 data: Expecting value: line 1 column 1 (char 0)
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 283, in _async_refresh
    self.data = await self._async_update_data()
                ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/homeassistant/homeassistant/helpers/update_coordinator.py", line 242, in _async_update_data
    return await self.update_method()
           ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/config/custom_components/enphase_envoy/__init__.py", line 82, in async_update_data
    data[description.key] = await envoy_reader.consumption_phase(
                            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/config/custom_components/enphase_envoy/envoy_reader.py", line 584, in consumption_phase
    raw_json = self.endpoint_production_json_results.json()
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/httpx/_models.py", line 756, in json
    return jsonlib.loads(self.text, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/json/__init__.py", line 346, in loads
    return _default_decoder.decode(s)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/json/decoder.py", line 337, in decode
    obj, end = self.raw_decode(s, idx=_w(s, 0).end())
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/json/decoder.py", line 355, in raw_decode
    raise JSONDecodeError("Expecting value", s, err.value) from None
json.decoder.JSONDecodeError: Expecting value: line 1 column 1 (char 0)
madbrain76 commented 12 months ago

Here is a log from the current main (broken case).

home-assistant_2023-07-22T21-58-10.423Z.log

catsmanac commented 12 months ago

Too bad, seems we need to unraffle the issue further. This time it's referring to a 3 phase consumption logic which it should not for the legacy Envoy. Thanks for the logfile

madbrain76 commented 12 months ago

Yes, I just attached the log, our messages crossed.

catsmanac commented 12 months ago

I'm still having issues with my Envoy-R with the main branch, but mine also doesn't work with any of the older branches either. Is there anything I need to clear out first?

error_log.txt

@DMedina559, looking at your logfile it looks like it's trying to get data for a recent ENVOY-S. It's also trying to get a token for ENVOY-S new firmware.

That doesn't seem to work

Config entry 'Envoy XXX' for enphase_envoy integration not ready yet: Error communicating with API: Illegal header value b'Bearer

When you configured this envoy, did you switch the option 'Use Enlighten' on? For older Envoy that option should be off. That switch enables the token logic for the newer firmware. If so, remove the envoy and re-add it with that switch disabled.

catsmanac commented 12 months ago

Found the newly surfaced issue and created a fix in PR #117.

@briancmpbll or @posixx can you merge again? (or allow me to merge)

DMedina559 commented 12 months ago

I'm still having issues with my Envoy-R with the main branch, but mine also doesn't work with any of the older branches either. Is there anything I need to clear out first? error_log.txt

@DMedina559, looking at your logfile it looks like it's trying to get data for a recent ENVOY-S. It's also trying to get a token for ENVOY-S new firmware.

That doesn't seem to work

Config entry 'Envoy XXX' for enphase_envoy integration not ready yet: Error communicating with API: Illegal header value b'Bearer

When you configured this envoy, did you switch the option 'Use Enlighten' on? For older Envoy that option should be off. That switch enables the token logic for the newer firmware. If so, remove the envoy and re-add it with that switch disabled.

No, I didn't check it. And I tried with every user/password combination. admin admin, installer, envoy.

DMedina559 commented 12 months ago

It's able to get Today's and Current production

2023-07-23 07:36:10.451 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] Fetched from http://192.168.86.29/api/v1/production: <Response [200 OK]>: { "wattHoursToday": 378, "wattHoursSevenDays": 103477, "wattHoursLifetime": 35697047, "wattsNow": 518

but then it tries getting the inverters with an unauthorized response

2023-07-23 07:36:10.489 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] Fetched from http://192.168.86.29/api/v1/production/inverters: <Response [401 Unauthorized]>: { "status": 401, "error": "", "info": "Authentication required", "moreInfo": "" }

Even though I have the correct code at line 464 in the reader file

self.get_inverters = False

Then that's when it goes on about the API even tho I haven't checked use enlighten for this gateway.

posixx commented 12 months ago

Found the newly surfaced issue and created a fix in PR #117.

@briancmpbll or @posixx can you merge again? (or allow me to merge)

Merged

madbrain76 commented 12 months ago

Thanks. Both my Envoys now work in the latest main.

catsmanac commented 12 months ago

Reopening to check @DMedina559's issue. @DMedina559 can you enable debug on your envoy and let it run in debug for some time. I've added code in the latest main that will tell what envoy it is in the log file.

2023-07-23 09:18:24.310 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] Using Model: P 

Any idea what firmware your envoy is using? The todays and lifetime production data report is the same as the ENVOY_S standard (not metered). The invertor production unauthorized seems to suggest it needs token authorization. Ever tried checking the 'Use Enlighten'switch and specify your enphase website username/password?

DMedina559 commented 12 months ago

My internet cable got damaged so I gotta wait till tomorrow for a new cable delivery to try enphase login, but my firmware version is R3.11.30 (0c976a)

catsmanac commented 12 months ago

@posixx when you committed 'Fix battery detection on old envoy version' what was the error reported then?

posixx commented 12 months ago

I don't know but it was for firmware D5.xx. The integration could not be added on my system without batteries without the fix when it was running D5.xx

catsmanac commented 12 months ago

I don't know but it was for firmware D5.xx. The integration could not be added on my system without batteries without the fix when it was running D5.xx

Ok, get it, thanks.

DMedina559 commented 12 months ago

@catsmanac when I try to log in with enlighten I get an "Unexpected Error" every time I try. Here's a log from the newest main branch

catsmanac commented 11 months ago

@DMedina559 looking at the log I think I found another spot that may cause this. Your Envoy firmware is R3.11 which marks it as an ENVOY with production data, which it has. After reading the production data it also tries to read the inverters page, for which it gets a 401 status back. Then it switches to the token mode which doesn't work either.

Can you access http://192.168.86.29/api/v1/production/inverters from your webbrowser? It probably will ask you to authorize with username/pw for that envoy? Or is it not accessible at all?

Looks like we need to come up with a way to not let the 401 status switch to the token mode for this case and diable inverter reading if it doesn't exist.

DMedina559 commented 11 months ago

@catsmanac just tried and I got an unauthorized error with the correct admin login

catsmanac commented 11 months ago

Thanks for testing @DMedina559. I just updated main with some code to not get inverters anymore after getting 401 for legacy models. Whenever you have time and feel like it can you give it a test?

You'll probably have to remove and re-add the legacy envoy to remove the 'use enlighten' option and change username and password back to what it was.

If possible, after getting the latest version running, switch on debug log again and then reload the legacy envoy from the integration menu in HA. With some luck we'll get the whole startup trail as well to verify if I'm on the right track. Let it run for a bit and disable debug again.

afbeelding

DMedina559 commented 11 months ago

@catsmanac Same issue unfortunately

catsmanac commented 11 months ago

Too bad, back to the drawing board. The error_log helps a lot, thanks. I see why it's failing now, now trying to work around it. It's like peeling the onion I'm afraid.

catsmanac commented 11 months ago

@DMedina559 , I'm back again for another try. Just updated main, lets hope we get 1 step further. Thanks for bearing with me.

DMedina559 commented 11 months ago

@catsmanac Still not loading sadly, but I'm glad to help anyway I can, let me know if you need anything else

catsmanac commented 11 months ago

I created an updated main. I have added some more logging to be able to fully trace why it is so persistent in not loading. There is a functional change too that may get it loaded, but I'm not really expecting it to work yet.

If you have access to the configuration folder on your home assistant system and you can edit configuration.yaml there then add to it:

logger:
  default: warning
  logs:
    custom_components.enphase_envoy: debug

This will set the envoy to debug logging from the get-go, no need to switch it on manually. We may catch some early details as well in this way.

posixx commented 11 months ago

Hello @catsmanac, your work is much appreciated. However for future bugfixing i would suggest you create a fork of this project and use that for debugging scenario's so we keep the main branch as clean as possible. Your fork can be added directly to HACS same as this one so no restrictions there.

catsmanac commented 11 months ago

Good point @posixx. I have the fork already, how can I tell HACS to use a branch rather then main?

posixx commented 11 months ago
catsmanac commented 11 months ago

Right, thanks. But main in my fork is main from Brians so that gets synced when Brains main is updated. I have the code to test in a branch in my fork and that doesn't show in HACS download option. Or am I missing something?

catsmanac commented 11 months ago

Found it, had to set my default branch to dev where I have latest update.