[BUG] Initial configuration failed

[itguy013]

[BUG] Initial configuration failed

[vincentwolsink]

Hi! Are there also any errors in the logs? Usually when this happens the previous integration was not fully removed. Please make sure that the custom_components/enphase_envoy dir is completely removed before installing this one.

[itguy013]

Deleted the dir custom_components/enphase_envoy. Rebooted, tried to configure the integration but still failed to initialize.

024-05-01 10:39:36.289 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] Checking Token value:
2024-05-01 10:39:36.289 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] Found empty token:
2024-05-01 10:39:36.289 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] Fetching envoy token
2024-05-01 10:39:36.295 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] Local auth secret:
2024-05-01 10:39:36.295 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] Doing authorize at entrez, with codeChallenge:
2024-05-01 10:39:36.940 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] Checking JWT on envoy with params {'client_id': 'envoy-ui-1', 'code': '', 'code_verifier': '', 'grant_type': 'authorization_code', 'redirect_uri': 'https://xxx.xxx.xxx.xxx/auth/callback'}
2024-05-01 10:39:47.449 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] Envoy Token
2024-05-01 10:39:47.449 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] Token expires at: 2024-05-01 22:39:44
2024-05-01 10:39:47.452 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] Token expires at: 2024-05-01 22:39:44
2024-05-01 10:39:47.452 INFO (MainThread) [custom_components.enphase_envoy.envoy_reader] TOKEN TYPE: installer
2024-05-01 10:39:47.452 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] HTTP POST Attempt: https://xxx.xxx.xxx.xxx/auth/check_jwt
2024-05-01 10:39:47.452 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] HTTP POST Data: None
2024-05-01 10:39:47.737 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] HTTP POST https://xxx.xxx.xxx.xxx/auth/check_jwt: <Response [200 OK]>:

Valid token.

2024-05-01 10:39:47.738 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] HTTP POST Cookie: <Cookies[]>
2024-05-01 10:39:47.739 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] We got a session cookie (sessionId), empty the auth header
2024-05-01 10:39:47.739 INFO (MainThread) [custom_components.enphase_envoy.envoy_reader] Updating endpoints ['endpoint_production_json']
2024-05-01 10:39:47.740 INFO (MainThread) [custom_components.enphase_envoy.envoy_reader] UPDATING ENDPOINT endpoint_production_json: https://{}/production.json?details=1
2024-05-01 10:39:47.740 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] HTTP GET Attempt #1: https://xxx.xxx.xxx.xxx/production.json?details=1: Header:{} Cookies:<Cookies[]>

2024-05-01 10:39:54.271 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] Fetched from https://xxx.xxx.xxx.xxx/production.json?details=1: <Response [200 OK]>: {"production":[{"type":"inverters","activeCount":14,"readingTime":1714552732,"wNow":2623,"whLifetime":503013},{"type":"eim","activeCount":1,"measurementType":"production","readingTime":1714552780,"wNow":2673.771,"whLifetime":14969957.303,"varhLeadLifetime":0.011,"varhLagLifetime":6249342.449,"vahLifetime":19540611.945,"rmsCurrent":11.224,"rmsVoltage":240.1,"reactPwr":248.343,"apprntPwr":2695.213,"pwrFactor":0.99,"whToday":4800.303,"whLastSevenDays":125572.303,"vahToday":6725.945,"varhLeadToday":0.011,"varhLagToday":2506.449,"lines":[{"wNow":2673.771,"whLifetime":14969957.303,"varhLeadLifetime":0.011,"varhLagLifetime":6249342.449,"vahLifetime":19540611.945,"rmsCurrent":11.224,"rmsVoltage":240.1,"reactPwr":248.343,"apprntPwr":2695.213,"pwrFactor":0.99,"whToday":4800.303,"whLastSevenDays":125572.303,"vahToday":6725.945,"varhLeadToday":0.011,"varhLagToday":2506.449}]}],"consumption":[{"type":"eim","activeCount":1,"measurementType":"total-consumption","readingTime":1714552780,"wNow":194.092,"whLifetime":12126093.537,"varhLeadLifetime":9517410.271,"varhLagLifetime":-6249198.632,"vahLifetime":26572894.436,"rmsCurrent":0.732,"rmsVoltage":240.123,"reactPwr":-85.642,"apprntPwr":175.709,"pwrFactor":1.0,"whToday":2302.537,"whLastSevenDays":23.537,"vahToday":7959.436,"varhLeadToday":3571.271,"varhLagToday":0.0,"lines":[{"wNow":194.092,"whLifetime":12126093.537,"varhLeadLifetime":9517410.271,"varhLagLifetime":-6249198.632,"vahLifetime":26572894.436,"rmsCurrent":0.732,"rmsVoltage":240.123,"reactPwr":-85.642,"apprntPwr":175.709,"pwrFactor":1.0,"whToday":2302.537,"whLastSevenDays":23.537,"vahToday":7959.436,"varhLeadToday":3571.271,"varhLagToday":0.0}]},{"type":"eim","activeCount":1,"measurementType":"net-consumption","readingTime":1714552780,"wNow":-2479.679,"whLifetime":-2843461.555,"varhLeadLifetime":9517410.282,"varhLagLifetime":143.818,"vahLifetime":26572894.436,"rmsCurrent":-10.492,"rmsVoltage":240.123,"reactPwr":-333.985,"apprntPwr":-2519.394,"pwrFactor":-1.0,"whToday":0,"whLastSevenDays":0,"vahToday":0,"varhLeadToday":0,"varhLagToday":0,"lines":[{"wNow":-2479.679,"whLifetime":-2843461.555,"varhLeadLifetime":9517410.282,"varhLagLifetime":143.818,"vahLifetime":26572894.436,"rmsCurrent":-10.492,"rmsVoltage":240.123,"reactPwr":-333.985,"apprntPwr":-2519.394,"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"}]}
2024-05-01 10:39:54.273 INFO (MainThread) [custom_components.enphase_envoy.envoy_reader] - FETCHING ENDPOINT endpoint_production_json TOOK 6.5335 seconds
2024-05-01 10:39:54.275 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] Resolving jsonpath endpoint_ensemble_power.devices:
2024-05-01 10:39:54.276 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] the configured path endpoint_ensemble_power.devices: did not return anything!
2024-05-01 10:39:54.276 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] Resolving jsonpath endpoint_ensemble_inventory[0].devices
2024-05-01 10:39:54.276 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] the configured path endpoint_ensemble_inventory[0].devices did not return anything!
2024-05-01 10:39:54.276 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] Resolving jsonpath endpoint_ensemble_power.devices:
2024-05-01 10:39:54.276 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] the configured path endpoint_ensemble_power.devices: did not return anything!
2024-05-01 10:39:54.276 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] Resolving jsonpath endpoint_home_json.enpower.grid_status
2024-05-01 10:39:54.277 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] the configured path endpoint_home_json.enpower.grid_status did not return anything!
2024-05-01 10:39:54.277 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] Resolving jsonpath endpoint_inventory.[?(@.type=='PCU')].devices[?(@.dev_type==1)]
2024-05-01 10:39:54.277 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] the configured path endpoint_inventory.[?(@.type=='PCU')].devices[?(@.dev_type==1)] did not return anything!
2024-05-01 10:39:54.277 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] Resolving jsonpath endpoint_devstatus.pcu[?(@.devType==1)]
2024-05-01 10:39:54.277 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] the configured path endpoint_devstatus.pcu[?(@.devType==1)] did not return anything!
2024-05-01 10:39:54.277 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] Resolving jsonpath endpoint_production_power.powerForcedOff
2024-05-01 10:39:54.277 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] the configured path endpoint_production_power.powerForcedOff did not return anything!
2024-05-01 10:39:54.277 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] Resolving jsonpath endpoint_inventory.[?(@.type=='NSRB')].devices[?(@.dev_type==12)]
2024-05-01 10:39:54.278 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] the configured path endpoint_inventory.[?(@.type=='NSRB')].devices[?(@.dev_type==12)] did not return anything!
2024-05-01 10:39:54.278 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] Resolving jsonpath endpoint_devstatus.pcu[?(@.devType==12)]
2024-05-01 10:39:54.278 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] the configured path endpoint_devstatus.pcu[?(@.devType==12)] did not return anything!
2024-05-01 10:39:54.278 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] Resolving jsonpath endpoint_devstatus.nsrb
2024-05-01 10:39:54.278 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] the configured path endpoint_devstatus.nsrb did not return anything!
2024-05-01 10:39:54.278 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] Resolving jsonpath endpoint_inventory.[?(@.type=='NSRB')].devices[?(@.dev_type==12)]
2024-05-01 10:39:54.278 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] the configured path endpoint_inventory.[?(@.type=='NSRB')].devices[?(@.dev_type==12)] did not return anything!
2024-05-01 10:39:54.279 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] EnvoyData.get(relay_info) -> {}
2024-05-01 10:39:54.279 INFO (MainThread) [custom_components.enphase_envoy.envoy_reader] Updating endpoints {'endpoint_home_json', 'endpoint_ensemble_inventory', 'endpoint_ensemble_power', 'endpoint_inventory', 'endpoint_installer_agf', 'endpoint_production_report', 'endpoint_production_json', 'endpoint_info', 'endpoint_devstatus', 'endpoint_ensemble_secctrl', 'endpoint_production_power'}
2024-05-01 10:39:54.279 INFO (MainThread) [custom_components.enphase_envoy.envoy_reader] UPDATING ENDPOINT endpoint_home_json: https://{}/home.json
2024-05-01 10:39:54.279 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] HTTP GET Attempt #1: https://xxx.xxx.xxx.xxx/home.json: Header:{} Cookies:<Cookies[]>
2024-05-01 10:40:15.107 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] TransportError: peer closed connection without sending complete message body (incomplete chunked read)
2024-05-01 10:40:15.109 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] HTTP GET Attempt #2: https://xxx.xxx.xxx.xxx/home.json: Header:{} Cookies:<Cookies[]>
2024-05-01 10:40:26.975 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] TransportError: peer closed connection without sending complete message body (incomplete chunked read)
2024-05-01 10:40:26.975 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] HTTP GET Attempt #3: https://xxx.xxx.xxx.xxx/home.json: Header:{} Cookies:<Cookies[]>
2024-05-01 10:40:36.293 DEBUG (MainThread) [custom_components.enphase_envoy] Finished fetching envoy Envoy 122103022093 data in 60.004 seconds (success: False)

[vincentwolsink]

Your Envoy does not respond in time to the request of home.json. You can try to power cycle your Envoy, usually this resolves the issue.

[itguy013]

Still got the same error after rebooting the envoy:

2024-05-01 21:44:57.919 DEBUG (MainThread) [custom_components.enphase_envoy.envoy_reader] TransportError: peer closed connection without sending complete message body (incomplete chunked read).

Anything else I can try to let this work? This is after it tries to connect to home.json

[vincentwolsink]

Very strange. Does it work if you manually fetch home.json via your browser?