Multiple "is taking over 10 seconds" warnings after updating to 2022.6.7

ShadowRep commented 2 years ago

The problem

The following warnings appeared in my log after the update to b 2022.6.7. Nothing else changed and everything seems to be working fine.

Setup of update platform hassio is taking over 10 seconds.
21:33:23 – (WARNING) Update

Setup of binary_sensor platform hassio is taking over 10 seconds.
21:33:23 – (WARNING) Binary sensor

Setup of input_text is taking over 10 seconds.
21:33:23 – (WARNING) /usr/local/lib/python3.9/asyncio/events.py - message first occurred at 21:33:23 and shows up 10 times

Setup of scene platform homeassistant is taking over 10 seconds.
21:33:23 – (WARNING) Scene

What version of Home Assistant Core has the issue?

core-2022.6.7

What was the last working version of Home Assistant Core?

core-2022.6.6

What type of installation are you running?

Home Assistant OS

Integration causing the issue

unknown

Link to integration documentation on our website

No response

Diagnostics information

No response

Example YAML snippet

No response

Anything in the logs that might be useful for us?

2022-06-22 21:33:23 WARNING (MainThread) [homeassistant.setup] Setup of zone is taking over 10 seconds.
2022-06-22 21:33:23 WARNING (MainThread) [homeassistant.setup] Setup of group is taking over 10 seconds.
2022-06-22 21:33:23 WARNING (MainThread) [homeassistant.setup] Setup of input_boolean is taking over 10 seconds.
2022-06-22 21:33:23 WARNING (MainThread) [homeassistant.components.scene] Setup of scene platform homeassistant is taking over 10 seconds.
2022-06-22 21:33:23 WARNING (MainThread) [homeassistant.setup] Setup of input_number is taking over 10 seconds.
2022-06-22 21:33:23 WARNING (MainThread) [homeassistant.setup] Setup of counter is taking over 10 seconds.
2022-06-22 21:33:23 WARNING (MainThread) [homeassistant.setup] Setup of input_text is taking over 10 seconds.
2022-06-22 21:33:23 WARNING (MainThread) [homeassistant.setup] Setup of input_datetime is taking over 10 seconds.
2022-06-22 21:33:23 WARNING (MainThread) [homeassistant.setup] Setup of timer is taking over 10 seconds.
2022-06-22 21:33:23 WARNING (MainThread) [homeassistant.setup] Setup of input_button is taking over 10 seconds.
2022-06-22 21:33:23 WARNING (MainThread) [homeassistant.setup] Setup of input_select is taking over 10 seconds.
2022-06-22 21:33:23 WARNING (MainThread) [homeassistant.components.binary_sensor] Setup of binary_sensor platform hassio is taking over 10 seconds.

Additional information

No response

KitHubek commented 2 years ago

the same here:

2022-06-22 21:29:57 WARNING (MainThread) [homeassistant.components.binary_sensor] Setup of binary_sensor platform hassio is taking over 10 seconds.
2022-06-22 21:29:57 WARNING (MainThread) [homeassistant.components.update] Setup of update platform hassio is taking over 10 seconds.
2022-06-22 21:29:57 WARNING (MainThread) [homeassistant.setup] Setup of timer is taking over 10 seconds.
2022-06-22 21:29:57 WARNING (MainThread) [homeassistant.setup] Setup of input_button is taking over 10 seconds.
2022-06-22 21:29:57 WARNING (MainThread) [homeassistant.setup] Setup of input_boolean is taking over 10 seconds.
2022-06-22 21:29:57 WARNING (MainThread) [homeassistant.setup] Setup of input_text is taking over 10 seconds.
2022-06-22 21:29:57 WARNING (MainThread) [homeassistant.setup] Setup of group is taking over 10 seconds.
2022-06-22 21:29:57 WARNING (MainThread) [homeassistant.setup] Setup of application_credentials is taking over 10 seconds.
2022-06-22 21:29:57 WARNING (MainThread) [homeassistant.setup] Setup of input_number is taking over 10 seconds.
2022-06-22 21:29:57 WARNING (MainThread) [homeassistant.setup] Setup of zone is taking over 10 seconds.
2022-06-22 21:29:57 WARNING (MainThread) [homeassistant.setup] Setup of input_select is taking over 10 seconds.
2022-06-22 21:29:57 WARNING (MainThread) [homeassistant.setup] Setup of counter is taking over 10 seconds.
2022-06-22 21:29:57 WARNING (MainThread) [homeassistant.setup] Setup of input_datetime is taking over 10 seconds.
2022-06-22 21:29:57 WARNING (MainThread) [homeassistant.setup] Setup of tag is taking over 10 seconds.
2022-06-22 21:29:57 WARNING (MainThread) [homeassistant.components.scene] Setup of scene platform homeassistant is taking over 10 seconds.
2022-06-22 21:30:04 WARNING (MainThread) [homeassistant.components.switch] Setup of switch platform wake_on_lan is taking over 10 seconds.
2022-06-22 21:31:01 WARNING (MainThread) [homeassistant.components.button] Setup of button platform nam is taking over 10 seconds.
2022-06-22 21:31:01 WARNING (MainThread) [homeassistant.components.sensor] Setup of sensor platform nam is taking over 10 seconds.

mbuico commented 2 years ago

Same here, even after multiple restarts.. I've moved from 2022.6.5 to 2022.6.7

2022-06-23 20:25:37 WARNING (MainThread) [homeassistant.components.binary_sensor] Setup of binary_sensor platform hassio is taking over 10 seconds.
2022-06-23 20:25:37 WARNING (MainThread) [homeassistant.setup] Setup of folder_watcher is taking over 10 seconds.
2022-06-23 20:25:37 WARNING (MainThread) [homeassistant.setup] Setup of input_number is taking over 10 seconds.
2022-06-23 20:25:37 WARNING (MainThread) [homeassistant.setup] Setup of input_boolean is taking over 10 seconds.
2022-06-23 20:25:37 WARNING (MainThread) [homeassistant.setup] Setup of counter is taking over 10 seconds.
2022-06-23 20:25:37 WARNING (MainThread) [homeassistant.setup] Setup of input_datetime is taking over 10 seconds.
2022-06-23 20:25:37 WARNING (MainThread) [homeassistant.setup] Setup of timer is taking over 10 seconds.
2022-06-23 20:25:37 WARNING (MainThread) [homeassistant.setup] Setup of tag is taking over 10 seconds.
2022-06-23 20:25:37 WARNING (MainThread) [homeassistant.setup] Setup of input_text is taking over 10 seconds.
2022-06-23 20:25:37 WARNING (MainThread) [homeassistant.setup] Setup of zone is taking over 10 seconds.
2022-06-23 20:25:37 WARNING (MainThread) [homeassistant.setup] Setup of input_button is taking over 10 seconds.
2022-06-23 20:25:37 WARNING (MainThread) [homeassistant.setup] Setup of group is taking over 10 seconds.
2022-06-23 20:25:37 WARNING (MainThread) [homeassistant.setup] Setup of application_credentials is taking over 10 seconds.
2022-06-23 20:25:37 WARNING (MainThread) [homeassistant.setup] Setup of input_select is taking over 10 seconds.
2022-06-23 20:25:37 WARNING (MainThread) [homeassistant.components.update] Setup of update platform hassio is taking over 10 seconds.

davidcom2 commented 2 years ago

Same here. I moved from 2022.5.4 to 2022.6.7. It's breaking my Wake On Lan switches.

I'm running HA on Oracle VM VirtualBox 6.1, installed on Windows 10.

davidcom2 commented 2 years ago

@ShadowRep @KitHubek @mbuico Hello all. Has anyone found a solution to this? I have several "is taking over 10 seconds" warnings. One of them is a wake_on_lan switch I have set up. The wake on lan functionality works for the first couple hours after a fresh reboot, but the error messages keep piling up in the log and ultimately the WOL functionality stops working.

chumbazoid commented 2 years ago

Same issue with multiple "taking over 10 seconds" warnings, HA Supervised on Debian 11.

Disappears upon reversion to 2022.6.6.

So which change in 2022.6.7 is causing this? Not seeing an obvious candidate on initial glance.

ShadowRep commented 2 years ago

@ShadowRep @KitHubek @mbuico Hello all. Has anyone found a solution to this? I have several "is taking over 10 seconds" warnings. One of them is a wake_on_lan switch I have set up. The wake on lan functionality works for the first couple hours after a fresh reboot, but the error messages keep piling up in the log and ultimately the WOL functionality stops working.

I don't know what causes this and I have no idea where to even start to look for a solution. I am not even sure someone who has the knowledge to correct this error has even seen this. The WOL feature breaking after a few hours seems to be an even bigger problem.

ShadowRep commented 2 years ago

Sorry. Did not mean to close this.

gfn256 commented 2 years ago

Have exactly the same issue since updating to 2022.6.7. I'm running hassio on Rpi4 8gb on SSD drive.

Logs from everyday on scheduled reboot:

2022-06-28 03:09:43 WARNING (MainThread) [homeassistant.setup] Setup of zone is taking over 10 seconds. 2022-06-28 03:09:43 WARNING (MainThread) [homeassistant.setup] Setup of timer is taking over 10 seconds. 2022-06-28 03:09:43 WARNING (MainThread) [homeassistant.setup] Setup of input_button is taking over 10 seconds. 2022-06-28 03:09:43 WARNING (MainThread) [homeassistant.setup] Setup of input_text is taking over 10 seconds. 2022-06-28 03:09:43 WARNING (MainThread) [homeassistant.setup] Setup of input_datetime is taking over 10 seconds. 2022-06-28 03:09:43 WARNING (MainThread) [homeassistant.setup] Setup of counter is taking over 10 seconds. 2022-06-28 03:09:43 WARNING (MainThread) [homeassistant.setup] Setup of input_boolean is taking over 10 seconds. 2022-06-28 03:09:43 WARNING (MainThread) [homeassistant.setup] Setup of input_select is taking over 10 seconds. 2022-06-28 03:09:43 WARNING (MainThread) [homeassistant.setup] Setup of input_number is taking over 10 seconds.

Thrasher2020 commented 2 years ago

Same issue - I have noticed that I have multiple homeassistant processes running when these errors occur. I've written a sensor and automation to kill them off when they appear. System has been a lot happier since! This is a straight 64bit HASSOS install on an RPI4

benjani85 commented 2 years ago

Same is happening to me since upgrading to 2022.6.7 - running on RPi4 as well

woytekbode commented 2 years ago

Same issue. RPi4 with SSD.

JoJa1101 commented 2 years ago

Same here, running HASS supervised on VM

erkr commented 2 years ago

Same here on a Pi4B 4gb. Also my startup increased significant. On core 2022.6.6 and before, only the fritzbox start time was slow ( typically 60 sec) and all other integrations where well below 30 sec. Now ca 5 integrations, including supervisor, are above the 30 seconds. For some reason especially RFLink is impacted (from 20 to 100 seconds). I presume that integration wasn't changed for a long time!!!

bdraco commented 2 years ago

Since there were only integration/lib changes in 2022.6.7, please let out your integrations, and try to narrow it down to everyone having the same one

chumbazoid commented 2 years ago

Thanks for giving attention, bdraco.

My integrations:

AdGuard Home
Apple TV
Broadlink
DLNA Digital Media Renderer
DLNA Digital Media Server
HACS
Home Assistant Supervisor
HomeKit
Kodi
Meteorologisk Institutt (Met.no)
Mobile App
MQTT
Netgear [disabled by user]
Radio Browser
Sun
Tasmota
Tuya

Of those, only MQTT saw changes in 2022.6.7: #73577 & #73619. Interested to see others' lists...

CaptTom9 commented 2 years ago

I don't know where to get the list of integrations, but just looking at the above the only ones I know I have in common are Broadlink and Sun. I'm seeing the same issue with multiple "over 10 seconds" warnings. RPi3B+, HAOS 8.2, Core 2022.6.7.

ShadowRep commented 2 years ago

My Integrations:

Adaptive Lighting Alarmo AVM FRITZ!Box Tools DNS IP Generic Camera HACS Meteorologisk institutt (Met.no) Mobile App Nuki Philips hue Raspberry Pi Power Supply Checker Shelly Sun Z-Wave JS Zigbee Home Automation

Add-ons:

AdGuard Home Duck DNS File editor Home Assistant Google Drive Backup MariaDB Mosquitto broker (not active) NGINX Home Assistant SSL proxy Node-RED phpMyAdmin SSH & Web Terminal Studio Code Server WireGuard Z-Wave JS (deactivated) Z-Wave JS to MQTT Zigbee2mqtt (deactivated)

Raspberry Pi 4, 8 GB, SSD drive

ShadowRep commented 2 years ago

So in my case I have only 7 things in common with @chumbazoid :

AdGuard Home
HACS
Home Assistant Supervisor
Meteorologisk Institut (Met.no)
Mobile App
MQTT (If it is Mosquitto. But mine is deactivated.)
Sun

ShadowRep commented 2 years ago

@CaptTom9: Settings --> Devices & Services --> Integrations

@ShadowRep: MQTT is the integration and yes I'm also using the Mosquitto Broker add-on. (They aren't the exact same thing.) Under Integrations, do you have MQTT ignored/disabled?

Sorry for the confusion.

And yes, Mosquitto broker MQTT is installed as an integration and disabled.

I also have some more ignored integrations:

UPnP/IGD
HomeKit Controller
LG webOS Smart TV
Google Cast
DLNA Digital Media Renderer
AVM FRITZ!SmartHome
Apple TV

bdraco commented 2 years ago

MQTT sure looks like a candidate to investigate more based on the data.

If anyone running the 2022.7 beta? If so did the problem go away?

woytekbode commented 2 years ago

@bdraco I don't think I'm running MQTT as an integration. Or is that something that runs default?

erkr commented 2 years ago

I'm running these integrations:

fritzbox
google cast
HACS
supervisor
home kit
harmony
MQTT
music assistant
ups network tools
notifications for android TV
Philips hue
MariaDB
scheduler
core vlc
ZHA

MQTT was changed a lot recently, deprecating the legacy way of configuring

mbuico commented 2 years ago

Mine on rpi3b+ sd drive

AVM FRITZ!Box Tools
HomeKit Controller
LG webOS Smart TV
MQTT
Network UPS Tools (NUT)
Raspberry Pi Power Supply Checker
Samsung Smart TV
Sonos
Supervisor
Home Assistant iOS
Sun

Looking at the integration's startup times seems the fritz!box tools is taking longer than the others..

KitHubek commented 2 years ago

here:

Adnotacja 2022-06-30 202022

ShadowRep commented 2 years ago

Mine:

Screenshot 2022-06-30 203113

bdraco commented 2 years ago

Please collect a py-spy on the affected system

Instructions here: https://community.home-assistant.io/t/how-to-install-py-spy-on-a-ha-os-instance-please-instruct/430822/44?u=bdraco

If you post the svg here be sure to zip it up first as GitHub will reformat it and it won't be useful for debugging. Otherwise send me a link to nick@koston.org and I'll take a look

chumbazoid commented 2 years ago

Please collect a py-spy on the affected system

Please find output from the commands below in the following zip: 73863_py-spy.zip

./py-spytop--pid60 --> py-spytop--pid60.txt
./py-spy record --pid 60 --duration 120 --rate 100 --> 60-2022-06-30T18%3A24%3A51-07%3A00.svg
./py-spy record --pid 60 --duration 300 --rate 100 --> 60-2022-06-30T18%3A35%3A23-07%3A00.svg
./py-spy dump --pid 60 --> py-spydump--pid60.txt

For the second svg (duration 300), I tried rate 200 as per the linked instructions but received error messages:

py-spy> 1.60s behind in sampling, results may be inaccurate. Try reducing the sampling rate py-spy> 1.89s behind in sampling, results may be inaccurate. Try reducing the sampling rate py-spy> 2.24s behind in sampling, results may be inaccurate. Try reducing the sampling rate [etc.]

Also tried rates 190, 180, ... 120 but errors persisted. No errors with rate 100, for the record.

Lastly, my HA log follows. Note that the custom integration and Kodi errors are (presumably) unrelated to present issue but am including everything for completeness.

2022-06-30 18:21:04 WARNING (SyncWorker_1) [homeassistant.loader] We found a custom integration hacs which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant 2022-06-30 18:21:04 WARNING (SyncWorker_1) [homeassistant.loader] We found a custom integration localtuya which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant 2022-06-30 18:21:26 WARNING (MainThread) [homeassistant.components.sensor] Setup of sensor platform time_date is taking over 10 seconds. 2022-06-30 18:21:26 WARNING (MainThread) [homeassistant.components.scene] Setup of scene platform homeassistant is taking over 10 seconds. 2022-06-30 18:21:26 WARNING (MainThread) [homeassistant.setup] Setup of zone is taking over 10 seconds. 2022-06-30 18:21:26 WARNING (MainThread) [homeassistant.setup] Setup of input_datetime is taking over 10 seconds. 2022-06-30 18:21:26 WARNING (MainThread) [homeassistant.setup] Setup of input_button is taking over 10 seconds. 2022-06-30 18:21:26 WARNING (MainThread) [homeassistant.setup] Setup of counter is taking over 10 seconds. 2022-06-30 18:21:26 WARNING (MainThread) [homeassistant.setup] Setup of input_number is taking over 10 seconds. 2022-06-30 18:21:26 WARNING (MainThread) [homeassistant.setup] Setup of input_select is taking over 10 seconds. 2022-06-30 18:21:26 WARNING (MainThread) [homeassistant.setup] Setup of input_text is taking over 10 seconds. 2022-06-30 18:21:26 WARNING (MainThread) [homeassistant.setup] Setup of input_boolean is taking over 10 seconds. 2022-06-30 18:21:26 WARNING (MainThread) [homeassistant.setup] Setup of timer is taking over 10 seconds. 2022-06-30 18:21:26 WARNING (MainThread) [homeassistant.components.sensor] Setup of sensor platform hassio is taking over 10 seconds. 2022-06-30 18:21:26 WARNING (MainThread) [homeassistant.components.update] Setup of update platform hassio is taking over 10 seconds. 2022-06-30 18:21:26 WARNING (MainThread) [homeassistant.components.binary_sensor] Setup of binary_sensor platform hassio is taking over 10 seconds. 2022-06-30 18:21:27 WARNING (MainThread) [homeassistant.config_entries] Config entry 'AdGuard Home' for adguard integration not ready yet: Timeout occurred while connecting to AdGuard Home instance.; Retrying in background 2022-06-30 18:21:42 WARNING (MainThread) [homeassistant.components.kodi.media_player] Unable to connect to Kodi via websocket 2022-06-30 18:21:42 WARNING (MainThread) [homeassistant.components.kodi.media_player] Unable to connect to Kodi via websocket 2022-06-30 18:21:59 WARNING (MainThread) [homeassistant.components.sensor] Setup of sensor platform adguard is taking over 10 seconds. 2022-06-30 18:21:59 WARNING (MainThread) [homeassistant.components.switch] Setup of switch platform adguard is taking over 10 seconds. 2022-06-30 18:30:16 ERROR (MainThread) [homeassistant.components.mobile_app.notify] Internal error encountered. This message is generated externally to Home Assistant.

Thank you.

bdraco commented 2 years ago

@chumbazoid

First some good news. 2022.7.x should improve performance on your system quite a bit based on your py-spy.

Unfortunately there isn't anything obvious causing startup to stall. Can you get a py-spy as close to startup as possible?

chumbazoid commented 2 years ago

Cheers and will look forward to 2022.7. Am working on Python literacy but that py-spy output is quite opaque to me.

Rebooted host machine and collected the attached immediately after HA came online: 73863_py-spy_V2.zip

Note that I had to reduce rate of the second SVG to 90.

HA log:

2022-06-30 20:30:02 WARNING (SyncWorker_0) [homeassistant.loader] We found a custom integration hacs which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant 2022-06-30 20:30:02 WARNING (SyncWorker_1) [homeassistant.loader] We found a custom integration localtuya which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant 2022-06-30 20:30:23 WARNING (MainThread) [homeassistant.components.sensor] Setup of sensor platform time_date is taking over 10 seconds. 2022-06-30 20:30:23 WARNING (MainThread) [homeassistant.setup] Setup of timer is taking over 10 seconds. 2022-06-30 20:30:23 WARNING (MainThread) [homeassistant.setup] Setup of input_datetime is taking over 10 seconds. 2022-06-30 20:30:23 WARNING (MainThread) [homeassistant.setup] Setup of localtuya is taking over 10 seconds. 2022-06-30 20:30:23 WARNING (MainThread) [homeassistant.setup] Setup of counter is taking over 10 seconds. 2022-06-30 20:30:23 WARNING (MainThread) [homeassistant.setup] Setup of input_boolean is taking over 10 seconds. 2022-06-30 20:30:23 WARNING (MainThread) [homeassistant.setup] Setup of input_select is taking over 10 seconds. 2022-06-30 20:30:23 WARNING (MainThread) [homeassistant.setup] Setup of input_number is taking over 10 seconds. 2022-06-30 20:30:23 WARNING (MainThread) [homeassistant.setup] Setup of zone is taking over 10 seconds. 2022-06-30 20:30:23 WARNING (MainThread) [homeassistant.setup] Setup of group is taking over 10 seconds. 2022-06-30 20:30:23 WARNING (MainThread) [homeassistant.setup] Setup of input_text is taking over 10 seconds. 2022-06-30 20:30:23 WARNING (MainThread) [homeassistant.components.scene] Setup of scene platform homeassistant is taking over 10 seconds. 2022-06-30 20:30:23 WARNING (MainThread) [homeassistant.setup] Setup of ffmpeg is taking over 10 seconds. 2022-06-30 20:30:23 WARNING (MainThread) [homeassistant.setup] Setup of input_button is taking over 10 seconds. 2022-06-30 20:30:23 WARNING (MainThread) [homeassistant.components.binary_sensor] Setup of binary_sensor platform hassio is taking over 10 seconds. 2022-06-30 20:30:23 WARNING (MainThread) [homeassistant.components.sensor] Setup of sensor platform hassio is taking over 10 seconds. 2022-06-30 20:30:23 WARNING (MainThread) [homeassistant.components.update] Setup of update platform hassio is taking over 10 seconds. 2022-06-30 20:30:23 WARNING (MainThread) [homeassistant.config_entries] Config entry 'AdGuard Home' for adguard integration not ready yet: Timeout occurred while connecting to AdGuard Home instance.; Retrying in background 2022-06-30 20:30:41 WARNING (MainThread) [homeassistant.components.kodi.media_player] Unable to connect to Kodi via websocket 2022-06-30 20:30:52 WARNING (MainThread) [homeassistant.components.sensor] Setup of sensor platform adguard is taking over 10 seconds. 2022-06-30 20:30:52 WARNING (MainThread) [homeassistant.components.switch] Setup of switch platform adguard is taking over 10 seconds.

chumbazoid commented 2 years ago

Was reading the py-spy thread and saw that ./py-spy top --pid ## output should be collected over 5 mins

I'd previously just captured it immediately after issuing the command. Rebooted the machine and let top run for 5 mins after HA started.

Updated file, if it matters: py-spytop--pid60_V3.txt

chumbazoid commented 2 years ago

FWIW, deleting the MQTT integration did not resolve this issue.

bdraco commented 2 years ago

Which hardware platform is everyone using ?

bdraco commented 2 years ago

Has anyone tried the 2022.7 beta yet to see if the problem goes away ?

bdraco commented 2 years ago

Cheers and will look forward to 2022.7. Am working on Python literacy but that py-spy output is quite opaque to me.

Rebooted host machine and collected the attached immediately after HA came online: 73863_py-spy_V2.zip

Note that I had to reduce rate of the second SVG to 90.

HA log:

The py-spy looks good, but it wasn't taken close enough to startup to capture it.

chumbazoid commented 2 years ago

Installed 2022.7.0b1 and no longer seeings warnings in log. Appears resolved to me.

bdraco commented 2 years ago

Great. I think the solution here is to wait for Wednesday release or try the beta if you are up for it (join #beta on discord if you do).

Mariusthvdb commented 2 years ago

MQTT sure looks like a candidate to investigate more based on the data.

If anyone running the 2022.7 beta? If so did the problem go away?

No did not change from before .

I mean the Mqtt. Not that speed didn’t change between 2022.6 and 2022.7. That speed difference is simply stunning!!

as a particular integration the command_line is mentioned consistently:

Logger: homeassistant.components.sensor
Source: /usr/local/lib/python3.10/asyncio/events.py:80 
Integration: Sensor (documentation, issues) 
First occurred: 08:40:16 (1 occurrences) 
Last logged: 08:40:16

Setup of sensor platform command_line is taking over 10 seconds.

and a specific one in particular:

Logger: homeassistant.bootstrap
Source: bootstrap.py:429 
First occurred: 08:40:21 (1 occurrences) 
Last logged: 08:40:21

Waiting on integrations to complete setup: sensor.command_line_5

however I am not sure which one that is, maybe the error could be made more concise and name the actual sensor?

Note this is not new to the current version, and has been there for a longer time

just a guess: if the number is the order of loading in the system, and that order would follow the order in the packages I use:

it would be the highlighted sensor, which is a set of sensors talking to my printer:

sensor:

  - platform: command_line
    name: Epson ink level Black
    command: /usr/bin/curl -k https://192.168.1.128/PRESENTATION/HTML/TOP/PRTINFO.HTML|awk -F"'" '/Ink_K.PNG/ && $6+0 == $6 { printf "%.0f\n", $6 / 50 * 100 }'
    unit_of_measurement: '%'
    scan_interval: 86400

if during startup the actual printer isnt online yet, this might cause trouble? The others are talking to my Hue bridges, which are always online, and the other one is a temp sensor for my mini PC which obviously is online too..

taking out the command_line in that packages solves the generic issue for command_line.... and leaves me with:

2022-07-01 10:30:50 WARNING (MainThread) [homeassistant.setup] Setup of rest is taking over 10 seconds.

which are 2 sensors talking to the SolarEdge converter and my Z-Wave hub, which both are always online too

charettepa commented 2 years ago

Which hardware platform is everyone using ? @bdraco

I'm running HA Blue (Odroid-n2) I have multiple (10 second) issues like others however, for me, what I really noticed, is the extreme difference in time before HA becomes reachable after reboot the loading of integrations is fairly quick but the amount of time that it says "unreachable" after a reboot used to be max 30seconds now its almost 4minutes

Thrasher2020 commented 2 years ago

I got this just now .....

charettepa commented 2 years ago

Update

my system reboots in less than 30 seconds again removing music assistant as an integration has resolved the issue

I then attempted to reload/reinstall in HACS then re-add the integration in HA once again a reboot takes almost 5 minutes just to access HA before the integrations even begin to load and my energy monitoring (emporia) even fails to load at all unless I perform a reload

I once again removed music assistant my HA reboots properly in 30 seconds again all integrations are loading correctly and quickly

there is something in music assistant causing this

bdraco commented 2 years ago

taking out the command_line in that packages solves the generic issue for command_line.... and leaves me with:

Executing a subprocess tends to be orders of magnitude slower than using rest or scrape. If you can avoid command_line sensors, your system will perform better

Mariusthvdb commented 2 years ago

Nick, are you saying we better use Rest commands than Command-line_line? My experience in the past has always been to keep rest sensors to a minimum because of the issues they threw, and command_line sensors would be less intrusive? (as in only happening on command....) I always update these manually only, and set an initial 86400 on them so they only are initiated at startup.

secondly, maybe related, so please let me ask about shell_command: I have several of these Z-wave switches I can read over mqtt, but need to control with shell_commands:

      tv_auditorium:
        friendly_name: Tv Auditorium
        unique_id: switch_tv_auditorium
        value_template: >
          {{is_state('binary_sensor.tv_auditorium_state','on')}}
        icon_template: >
           mdi:{{iif(is_state('binary_sensor.tv_auditorium_state','on'),
                 'television','television-off')}}
        turn_on:
          service: shell_command.tv_auditorium_on
        turn_off:
          service: shell_command.tv_auditorium_off

where the shell commands look like:

  tv_auditorium_on: >
    curl -X POST -d '{"seq":1, "method":"object_prop_set", "arguments":{"oid":"902051dd", "prop":"command", "value":"on"}}' http://192.168.1.27/iungo/api_request
  tv_auditorium_off: >
    curl -X POST -d '{"seq":1, "method":"object_prop_set", "arguments":{"oid":"902051dd", "prop":"command", "value":"off"}}' http://192.168.1.27/iungo/api_request

and the value_template is an mqtt binary.

would these cause any harm?

I can move them all to the zwave integration if that would perform better, and be lighter in the system as a whole

erkr commented 2 years ago

@charettepa:

Update

my system reboots in less than 30 seconds again

removing music assistant as an integration has resolved the issue

I'm running Music Assistent as well. On my setup, I clearly noted the moment of degradation when I updated to core-2022.6.7. No change to the MA at that moment.

So there is the possibility your issue with MA is specific on your system, and not related to this issue. And I see not all users reporting in this issue run MA either. So you can create an issue on the MA GitHub for that. Please include your startup log in that issue.

But I will deinstall MA on my setup as well, and report back the results.

erkr commented 2 years ago

@charettepa: I deinstalled MA, and that didn't make any difference in my setup. Probably you have a specific issue with MA. Edit: after reinstalling the start time of MA is just 1 second

Mariusthvdb commented 2 years ago

ok, so I got down to this:

starting up with my printer being online removes the warning for the command_line sensors. This is not a solution, but a test case scenario. I have it off most of the time, so hope some internal test can be added for this scenario, like "resource is offline".

levaing me with the rest command warning. Ive been Abel to take out the Solar Edge rest sensor (by migrating to the core Solar edge integration, which I believed to be a rest sensor in disguise....). And can confirm that without any other rest sensor, the warning disappears. But. I have these 3 little sensors under the rest integration left, that when brought back into the config, immediately throw the warning:

rest:

- <<: &config
  resource: !secret iungo_url
  scan_interval: 86400
  method: POST
payload: >
  {"seq":1, "method":"fw_get_remote_info"}
sensor:
  - unique_id: iungo_latest_firmware_rest
    name: Iungo latest firmware
    icon: mdi:counter
    value_template: >
      {{value_json.rv.fw.build}}
    json_attributes_path: $.rv.fw
    json_attributes:
      - build
      - date
      - status
      - version

- <<: *config
payload: >
  {"seq":1, "method":"sysinfo_version"}
sensor:
  - unique_id: iungo_current_firmware_rest
    name: Iungo current firmware
    icon: mdi:counter
    value_template: >
      {{value_json.rv.version.build}}
    json_attributes_path: $.rv.version
    json_attributes:
      - build
      - type
      - tag
      - date
      - time
      - serial

- <<: *config
payload: >
  {"seq":1, "method":"fw_get_status"}
binary_sensor:
  - name: Iungo firmware up to date
    value_template: >
      {{value_json.rv.fw == 'false'}}
    device_class: update

all in all, it seems that 1 entity of either integrations causes the warning to appear. Which really seems an issue. The Iungo device in these rest sensors is a local device, no cloud interfering at all, and even on the same GB switch, so no Lan issue either... Shouldn't happen unless an issue?

charettepa commented 2 years ago

dit: after reinstalling the start time of MA is just 1 second

my start time for MA is also ~1 second however all my integrations have very quick startup

my issue is specifically that HA itsself is not even accessible and does not even begin to start for almost 5 minutes with MA installed MA the integration itself starts in ~1 sec without MA installed HA becomes available (reachable) in less than 30 sec then all integrations load in ~10-15 sec

charettepa commented 2 years ago

So there is the possibility your issue with MA is specific on your system, and not related to this issue. And I see not all users reporting in this issue run MA either. So you can create an issue on the MA GitHub for that. Please include your startup log in that issue.

yes, you are correct that the issue seems different

erkr commented 2 years ago

@charettepa

yes, you are correct that the issue seems different

Can be an authorization issue with Spotify. Are you using Spotify and located in Denmark ?! There are issues with that region. Is the issue gone When you disable Spotify?

charettepa commented 2 years ago

No, I was only using tunein which only requires the user and no password

erkr commented 2 years ago

No, I was only using tunein

which only requires the user and no password

Please open an issue for that in the GitHub for MA if you need us to follow up on that. This issue is for the extra delay in starting up HA since core 2022.6.7.

home-assistant / core