search

vincentwolsink / home_assistant_enphase_envoy_installer

This is a HACS custom integration for Enphase Envoys with firmware version 7 and up.
Apache License 2.0
54 stars 10 forks source link

Failed setup enphase #90

Closed mvroosmalen1970 closed 9 months ago

mvroosmalen1970 commented 9 months ago

Describe the bug After update to core

Home Assistant 2023.9.1 Supervisor 2023.08.3 Operating System 10.5 Frontend 20230908.0 - latest

The enphase is not recognized any more

Envoy

Additional context

Relevant snippet of Home Assistant error log.

2023-09-10 07:48:16.257 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] Token expired on: 2023-09-09 14:23:34 2023-09-10 07:48:16.258 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] Found Expired token - Retrieving new token 2023-09-10 07:48:16.258 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] Fetching envoy token 2023-09-10 07:48:16.261 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] Local auth secret: xxxxxxxxxxxxxx 2023-09-10 07:48:16.261 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] Doing authorize at entrez, with codeChallenge: xxxxxxxxxxxxxxxxx 2023-09-10 07:48:16.842 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] Checking JWT on envoy with params {'client_id': 'envoy-ui-1', 'code': 'xxxxxxxxxxx', 'code_verifier': 'xxxxxxxxxxxxxxxxxxx', 'grant_type': 'authorization_code', 'redirect_uri': 'https://192.168.1.xx/auth/callback'} 2023-09-10 07:48:21.162 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] Envoy Token 2023-09-10 07:48:21.163 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] Token expires at: 2023-09-10 19:48:17 2023-09-10 07:48:21.163 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] Token expires at: 2023-09-10 19:48:17 2023-09-10 07:48:21.163 INFO (MainThread) [custom_components.enphase_envoy.envoy_reader] TOKEN TYPE: installer 2023-09-10 07:48:21.163 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] HTTP POST Attempt: https://192.168.1.xx/auth/check_jwt 2023-09-10 07:48:21.163 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] HTTP POST Data: None 2023-09-10 07:48:21.422 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] HTTP POST https://192.168.1.xx/auth/check_jwt: <Response [200 OK]>: <!DOCTYPE html>

Valid token.

2023-09-10 07:48:21.423 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] HTTP POST Cookie: <Cookies[<Cookie sessionId=xx for 192.168.1.xx />]> 2023-09-10 07:48:21.425 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] We got a session cookie (sessionId), empty the auth header 2023-09-10 07:48:21.425 INFO (MainThread) [custom_components.enphase_envoy.envoy_reader] Updating endpoints ['endpoint_production_json_results'] 2023-09-10 07:48:21.425 INFO (MainThread) [custom_components.enphase_envoy.envoy_reader] UPDATING ENDPOINT endpoint_production_json_results: https://{}/production.json?details=1 2023-09-10 07:48:21.425 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] HTTP GET Attempt #1: https://192.168.1.xx/production.json?details=1: Header:{} Cookies:<Cookies[<Cookie sessionId=xx for 192.168.1.xx />]> 2023-09-10 07:48:26.240 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] Fetched from https://192.168.1.xx/production.json?details=1: <Response [200 OK]>: {"production":[{"type":"inverters","activeCount":19,"readingTime":1694324919,"wNow":151,"whLifetime":265542},{"type":"eim","activeCount":0,"measurementType":"production","readingTime":1694324920,"wNow":0.173,"whLifetime":0.0,"varhLeadLifetime":0.0,"varhLagLifetime":0.0,"vahLifetime":0.0,"rmsCurrent":0.439,"rmsVoltage":249.252,"reactPwr":0.0,"apprntPwr":2.886,"pwrFactor":0.61,"whToday":0.0,"whLastSevenDays":0.0,"vahToday":0.0,"varhLeadToday":0.0,"varhLagToday":0.0,"lines":[{"wNow":0.0,"whLifetime":0.0,"varhLeadLifetime":0.0,"varhLagLifetime":0.0,"vahLifetime":0.0,"rmsCurrent":-0.0,"rmsVoltage":236.237,"reactPwr":0.0,"apprntPwr":-0.0,"pwrFactor":0.0,"whToday":0.0,"whLastSevenDays":0.0,"vahToday":0.0,"varhLeadToday":0.0,"varhLagToday":0.0},{"wNow":0.113,"whLifetime":0.0,"varhLeadLifetime":0.0,"varhLagLifetime":0.0,"vahLifetime":0.0,"rmsCurrent":0.186,"rmsVoltage":6.064,"reactPwr":0.0,"apprntPwr":1.125,"pwrFactor":0.0,"whToday":0.0,"whLastSevenDays":0.0,"vahToday":0.0,"varhLeadToday":0.0,"varhLagToday":0.0},{"wNow":0.06,"whLifetime":0.0,"varhLeadLifetime":0.0,"varhLagLifetime":0.0,"vahLifetime":0.0,"rmsCurrent":0.253,"rmsVoltage":6.951,"reactPwr":-0.0,"apprntPwr":1.761,"pwrFactor":1.0,"whToday":0.0,"whLastSevenDays":0.0,"vahToday":0.0,"varhLeadToday":0.0,"varhLagToday":0.0}]}],"consumption":[{"type":"eim","activeCount":0,"measurementType":"total-consumption","readingTime":1694324920,"wNow":-1.502,"whLifetime":0.0,"varhLeadLifetime":0.0,"varhLagLifetime":0.0,"vahLifetime":0.0,"rmsCurrent":0.121,"rmsVoltage":252.574,"reactPwr":-0.0,"apprntPwr":0.992,"pwrFactor":0.44,"whToday":0.0,"whLastSevenDays":0.0,"vahToday":0.0,"varhLeadToday":0.0,"varhLagToday":0.0,"lines":[{"wNow":0.0,"whLifetime":0.0,"varhLeadLifetime":0.0,"varhLagLifetime":0.0,"vahLifetime":0.0,"rmsCurrent":-0.0,"rmsVoltage":236.236,"reactPwr":-0.0,"apprntPwr":-0.0,"pwrFactor":1.0,"whToday":0.0,"whLastSevenDays":0.0,"vahToday":0.0,"varhLeadToday":0.0,"varhLagToday":0.0},{"wNow":-0.55,"whLifetime":0.0,"varhLeadLifetime":0.0,"varhLagLifetime":0.0,"vahLifetime":0.0,"rmsCurrent":0.061,"rmsVoltage":9.485,"reactPwr":0.0,"apprntPwr":0.575,"pwrFactor":-0.96,"whToday":0.0,"whLastSevenDays":0.0,"vahToday":0.0,"varhLeadToday":0.0,"varhLagToday":0.0},{"wNow":-0.952,"whLifetime":0.0,"varhLeadLifetime":0.0,"varhLagLifetime":0.0,"vahLifetime":0.0,"rmsCurrent":0.061,"rmsVoltage":6.854,"reactPwr":-0.0,"apprntPwr":0.416,"pwrFactor":-1.0,"whToday":0.0,"whLastSevenDays":0.0,"vahToday":0.0,"varhLeadToday":0.0,"varhLagToday":0.0}]},{"type":"eim","activeCount":0,"measurementType":"net-consumption","readingTime":1694324920,"wNow":-1.676,"whLifetime":0.0,"varhLeadLifetime":0.0,"varhLagLifetime":0.0,"vahLifetime":0.0,"rmsCurrent":-0.318,"rmsVoltage":252.574,"reactPwr":-0.0,"apprntPwr":-2.506,"pwrFactor":-1.0,"whToday":0,"whLastSevenDays":0,"vahToday":0,"varhLeadToday":0,"varhLagToday":0,"lines":[{"wNow":0.0,"whLifetime":0.0,"varhLeadLifetime":0.0,"varhLagLifetime":0.0,"vahLifetime":0.0,"rmsCurrent":0.0,"rmsVoltage":236.236,"reactPwr":-0.0,"apprntPwr":0.0,"pwrFactor":0.0,"whToday":0,"whLastSevenDays":0,"vahToday":0,"varhLeadToday":0,"varhLagToday":0},{"wNow":-0.664,"whLifetime":0.0,"varhLeadLifetime":0.0,"varhLagLifetime":0.0,"vahLifetime":0.0,"rmsCurrent":-0.125,"rmsVoltage":9.485,"reactPwr":0.0,"apprntPwr":-1.185,"pwrFactor":-1.0,"whToday":0,"whLastSevenDays":0,"vahToday":0,"varhLeadToday":0,"varhLagToday":0},{"wNow":-1.012,"whLifetime":0.0,"varhLeadLifetime":0.0,"varhLagLifetime":0.0,"vahLifetime":0.0,"rmsCurrent":-0.193,"rmsVoltage":6.854,"reactPwr":-0.0,"apprntPwr":-1.321,"pwrFactor":-1.0,"whToday":0,"whLastSevenDays":0,"vahToday":0,"varhLeadToday":0,"varhLagToday":0}]}],"storage":[{"type":"acb","activeCount":0,"readingTime":0,"wNow":0,"whNow":0,"state":"idle"}]} 2023-09-10 07:48:26.242 INFO (MainThread) [custom_components.enphase_envoy.envoy_reader] - FETCHING ENDPOINT endpoint_production_json_results TOOK 4.8166 seconds 2023-09-10 07:48:26.243 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] Resolving jsonpath endpoint_production_json_results.storage[0] 2023-09-10 07:48:26.243 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] the configured path endpoint_production_json_results.storage[0] did not return anything! 2023-09-10 07:48:26.243 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] Resolving jsonpath endpoint_ensemble_json_results[0].devices 2023-09-10 07:48:26.243 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] the configured path endpoint_ensemble_json_results[0].devices did not return anything! 2023-09-10 07:48:26.243 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] Resolving jsonpath endpoint_home_json_results.enpower.grid_status 2023-09-10 07:48:26.243 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] the configured path endpoint_home_json_results.enpower.grid_status did not return anything! 2023-09-10 07:48:26.244 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] Resolving jsonpath endpoint_inventory_results.[?(@.type=='PCU')].devices[?(@.dev_type==1)] 2023-09-10 07:48:26.244 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] the configured path endpoint_inventory_results.[?(@.type=='PCU')].devices[?(@.dev_type==1)] did not return anything! 2023-09-10 07:48:26.244 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] Resolving jsonpath endpoint_devstatus.pcu[?(@.devType==1)] 2023-09-10 07:48:26.244 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] the configured path endpoint_devstatus.pcu[?(@.devType==1)] did not return anything! 2023-09-10 07:48:26.244 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] Resolving jsonpath endpoint_production_power.powerForcedOff 2023-09-10 07:48:26.244 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] the configured path endpoint_production_power.powerForcedOff did not return anything! 2023-09-10 07:48:26.244 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] Resolving jsonpath endpoint_inventory_results.[?(@.type=='NSRB')].devices[?(@.dev_type==12)] 2023-09-10 07:48:26.244 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] the configured path endpoint_inventory_results.[?(@.type=='NSRB')].devices[?(@.dev_type==12)] did not return anything! 2023-09-10 07:48:26.244 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] Resolving jsonpath endpoint_devstatus.pcu[?(@.devType==12)] 2023-09-10 07:48:26.244 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] the configured path endpoint_devstatus.pcu[?(@.devType==12)] did not return anything! 2023-09-10 07:48:26.244 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] Resolving jsonpath endpoint_devstatus.nsrb 2023-09-10 07:48:26.244 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] the configured path endpoint_devstatus.nsrb did not return anything! 2023-09-10 07:48:26.244 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] Resolving jsonpath endpoint_inventory_results.[?(@.type=='NSRB')].devices[?(@.dev_type==12)] 2023-09-10 07:48:26.244 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] the configured path endpoint_inventory_results.[?(@.type=='NSRB')].devices[?(@.dev_type==12)] did not return anything! 2023-09-10 07:48:26.245 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] EnvoyData.get(relay_info) -> {} 2023-09-10 07:48:26.245 INFO (MainThread) [custom_components.enphase_envoy.envoy_reader] Updating endpoints {'endpoint_home_json_results', 'endpoint_production_power', 'endpoint_devstatus', 'endpoint_info_results', 'endpoint_pdm_energy', 'endpoint_inventory_results', 'endpoint_production_json_results', 'endpoint_ensemble_json_results'} 2023-09-10 07:48:26.245 INFO (MainThread) [custom_components.enphase_envoy.envoy_reader] UPDATING ENDPOINT endpoint_home_json_results: https://{}/home.json 2023-09-10 07:48:26.245 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] HTTP GET Attempt #1: https://192.168.1.xx/home.json: Header:{} Cookies:<Cookies[<Cookie sessionId=xxx for 192.168.1.xx />]> 2023-09-10 07:48:41.909 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] TransportError: peer closed connection without sending complete message body (incomplete chunked read) 2023-09-10 07:48:41.911 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] HTTP GET Attempt #2: https://192.168.1.xx/home.json: Header:{} Cookies:<Cookies[<Cookie sessionId=xx for 192.168.1.xx />]> 2023-09-10 07:48:53.870 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] TransportError: peer closed connection without sending complete message body (incomplete chunked read) 2023-09-10 07:48:53.870 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] HTTP GET Attempt #3: https://192.168.1.xx/home.json: Header:{} Cookies:<Cookies[<Cookie sessionId=xxxxx for 192.168.1.xx />]> 2023-09-10 07:49:06.404 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] TransportError: peer closed connection without sending complete message body (incomplete chunked read) 2023-09-10 07:49:06.405 DEBUG (MainThread) [custom_components.enphase_envoy] Finished fetching envoy Envoy xxxxx data in 50.148 seconds (success: False)

mvroosmalen1970 commented 9 months ago

Solved.... Think through logging in the enphase manually (using generated token) yesterday late. This morning values are being reported again..

tommyloon commented 9 months ago

I have the same problem. The enphase is not recognized any more after the latest update. Manual login is not helping. login with a token from https://entrez.enphaseenergy.com/ is working.

vincentwolsink commented 9 months ago

@tommyloon The integration did not change and I am not aware of any changes in the latest HA that could cause this. Have you tried to power off/on your Envoy?

mnederlof commented 9 months ago

For me it is working fine with latest HA version, so that is not the issue. Otherwise, remove the integration from your HA setup and add it again via HACS.

tommyloon commented 9 months ago

It's working again. Unfortunately i don't know what helpt but I did multiple integration deletes, installs, different integration installs, a core update and reboots of the envoy. Keep up the good work