GuyKh / iec-custom-component

HomeAssistant Custom Component for IEC
MIT License
123 stars 4 forks source link

Long startup time #131

Open maorcc opened 1 month ago

maorcc commented 1 month ago

System Health details

Version core-2024.7.3
Installation type Home Assistant OS
Development false
Supervisor true
Docker true
User root
Virtual environment false
Python version 3.12.4
Operating system family Linux
Operating system version 6.6.31-haos-raspi
CPU architecture aarch64
Configuration directory /config

Checklist

Describe the issue

The startup time for this integration takes 16 seconds on my RSPi5. It looks like a lot of data is fetched from the IEC cloud service during startup, and those services are slow. Can some data fetching be done after the startup to avoid delaying the Home Assistant Core startup time?

Reproduction steps

  1. Open the "Integration Startup Time" dialog. (Accessible from the "Repairs" page under the three-dots menu)
  2. Find the "Israel Electric Corporation (IEC)
  3. See that the time column shows a value of over 10 seconds

Alternatively, just see in the log a message like this one: Finished fetching Iec data in 16.265 seconds (success: True)

Debug logs

2024-07-30 00:28:27.296 INFO (MainThread) [homeassistant.setup] Setting up iec
2024-07-30 00:28:27.296 INFO (MainThread) [homeassistant.setup] Setup of domain iec took 0.00 seconds
2024-07-30 00:28:27.298 DEBUG (MainThread) [custom_components.iec.coordinator] Loading API token from config entry
2024-07-30 00:28:27.299 DEBUG (MainThread) [custom_components.iec.coordinator] Checking if API token needs to be refreshed
2024-07-30 00:28:27.301 DEBUG (MainThread) [iec_api.commons] HTTP GET: https://iecapi.iec.co.il//api/customer/contract/xxxxxxxxxxx

2024-07-30 00:28:29.932 DEBUG (MainThread) [iec_api.commons] HTTP GET Response <200>: {"data":{"contracts":[{"address":"....},"reponseDescriptor":{"isSuccess":true,"code":"0","description":""}}
2024-07-30 00:28:29.934 DEBUG (MainThread) [iec_api.commons] HTTP GET: https://iecapi.iec.co.il//api/content/en-US/calculators/gadget

2024-07-30 00:28:30.819 DEBUG (MainThread) [iec_api.commons] HTTP GET Response <200>: {
"gadget_Calculator_Rates": {
"lastUpdated": "2024-02-01T00:00:00Z",
...
},
"title": "Calculators BY Device"
}
2024-07-30 00:28:30.820 DEBUG (MainThread) [custom_components.iec.coordinator] All Contract Ids: [00000000]
2024-07-30 00:28:30.820 DEBUG (MainThread) [custom_components.iec.coordinator] Updating statistics for IEC Contract 000000000
2024-07-30 00:28:30.821 DEBUG (MainThread) [iec_api.commons] HTTP GET: https://iecapi.iec.co.il//api/Device/00000000
2024-07-30 00:28:30.834 DEBUG (MainThread) [iec_api.commons] HTTP GET: https://iecapi.iec.co.il//api/BillingCollection/invoices/0000000/000000000

2024-07-30 00:28:33.242 DEBUG (MainThread) [iec_api.commons] HTTP GET Response <200>: [{"isActive":true,"deviceType":3,"deviceNumber":"00000000","deviceCode":"000"}]

2024-07-30 00:28:33.312 DEBUG (MainThread) [custom_components.iec.coordinator] Last statistics are from 2024-07-29 09:00:00
2024-07-30 00:28:33.312 DEBUG (MainThread) [custom_components.iec.coordinator] Fetching consumption from 2024-07-29 09:00:00
2024-07-30 00:28:33.313 DEBUG (MainThread) [iec_api.commons] HTTP POST: https://iecapi.iec.co.il//api/Consumption/RemoteReadingRange/00000000

2024-07-30 00:28:33.325 DEBUG (MainThread) [iec_api.commons] HTTP Content POST: b'{"meterSerialNumber":"000000000","meterCode":"000","lastInvoiceDate":"2024-00-00","fromDate":"2024-00-00","resolution":0}'

2024-07-30 00:28:34.711 DEBUG (MainThread) [iec_api.commons] HTTP GET Response <200>: {"data":{"property":{"areaId":"...

2024-07-30 00:28:34.731 DEBUG (MainThread) [iec_api.commons] HTTP POST: https://iecapi.iec.co.il//api/Consumption/RemoteReadingRange/00000000
2024-07-30 00:28:34.733 DEBUG (MainThread) [iec_api.commons] HTTP Content POST: b'{"meterSerialNumber":"00000000","meterCode":"000","lastInvoiceDate":"2024-00-00","fromDate":"2024-00-00","resolution":0}'
2024-07-30 00:28:35.280 DEBUG (MainThread) [iec_api.commons] HTTP POST Response <200>: {"status":0,"futureConsumptionInfo":{"lastInvoiceDate":null,"currentDate":"2024-...

2024-07-30 00:28:35.287 DEBUG (MainThread) [custom_components.iec.coordinator] Fetching LongTerm Statistics since 2024-07-00 09:00:00
2024-07-30 00:28:35.303 DEBUG (MainThread) [custom_components.iec.coordinator] Last Consumption Sum for C[000000000] D[000000000]: 0000.00000000000
2024-07-30 00:28:35.303 DEBUG (MainThread) [custom_components.iec.coordinator] Last Estimated Cost Sum for C[000000000] D[000000000]: 0000.0000000000000000
2024-07-30 00:28:35.307 DEBUG (MainThread) [custom_components.iec.coordinator] LongTerm Statistics - Skipping 2024-07-00 09:00:00+03:00 data since it's already reported
2024-07-30 00:28:35.308 DEBUG (MainThread) [custom_components.iec.coordinator] LongTerm Statistics - Skipping 2024-07-00 10:00:00+03:00 since it's partial for the hour
2024-07-30 00:28:38.295 DEBUG (MainThread) [iec_api.commons] HTTP POST Response <200>: {"status":0,"futureConsumptionInfo":{"lastInvoiceDate":null,"currentDate":"2024-07-00","futureConsumption":null,"totalImport":...}
2024-07-30 00:28:38.304 DEBUG (MainThread) [custom_components.iec.coordinator] Daily reading for date: 2024-07-00 is present: 00.000
2024-07-30 00:28:38.306 DEBUG (MainThread) [iec_api.commons] HTTP POST: https://iecapi.iec.co.il//api/Consumption/RemoteReadingRange/0000000
2024-07-30 00:28:38.309 DEBUG (MainThread) [iec_api.commons] HTTP Content POST: b'{"meterSerialNumber":"000000000","meterCode":"000","lastInvoiceDate":"2024-00-00","fromDate":"2024-00-00","resolution":0}'
2024-07-30 00:28:42.039 DEBUG (MainThread) [iec_api.commons] HTTP POST Response <200>: {"status":0,"futureConsumptionInfo":{"lastInvoiceDate":null,"currentDate":"2024-00-00","futureConsumption":null,"totalImport":0000.000,"totalImportDate":"2024-00-00"},"fromDate":"2024-00-00","toDate":"2024-00-00","totalConsumptionForPeriod":null,"totalImportDateForPeriod":"2024-00-00","meterStartDate":"2024-00-00","totalImport":0000.000,"data":[]}
2024-07-30 00:28:42.040 DEBUG (MainThread) [custom_components.iec.coordinator] Daily reading for date: 2024-00-00 is missing, calculating manually
2024-07-30 00:28:42.041 DEBUG (MainThread) [custom_components.iec.coordinator] Daily reading for date: 2024-00-00 - using existing prefetched readings
2024-07-30 00:28:42.043 DEBUG (MainThread) [iec_api.commons] HTTP POST: https://iecapi.iec.co.il//api/Consumption/RemoteReadingRange/00000000
2024-07-30 00:28:42.047 DEBUG (MainThread) [iec_api.commons] HTTP Content POST: b'{"meterSerialNumber":"00000000","meterCode":"000","lastInvoiceDate":"2024-00-00","fromDate":"2024-00-00","resolution":0}'
2024-07-30 00:28:43.549 DEBUG (MainThread) [iec_api.commons] HTTP POST Response <200>: {"status":0,"futureConsumptionInfo":{"lastInvoiceDate":null,"currentDate":"2024-07-00","futureConsumption":...}]}
2024-07-30 00:28:43.563 DEBUG (MainThread) [custom_components.iec.coordinator] Finished fetching Iec data in 16.265 seconds (success: True)
2024-07-30 00:28:43.598 INFO (MainThread) [homeassistant.components.sensor] Setting up iec.sensor
2024-07-30 00:28:43.615 INFO (MainThread) [homeassistant.components.binary_sensor] Setting up iec.binary_sensor

Diagnostics dump

No response

GuyKh commented 1 month ago

@maorcc - is it blocking the startup of HA?

I had few people telling me that IEC API performance gone bad lately, not experiencing it myself.