Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Component <unknown> took a long time for an operation (0.08 s). #7

Open
no1knows opened this issue Aug 19, 2023 · 6 comments
Open

Component <unknown> took a long time for an operation (0.08 s). #7

no1knows opened this issue Aug 19, 2023 · 6 comments

Comments

@no1knows
Copy link

After updating the firmware to the latest version it doesn't appear to be trying to initiate the radio anymore:

INFO ESPHome 2023.8.1
INFO Reading configuration /config/esphome/iBoost.yaml...
INFO Starting log output from iboostesphome.local using esphome API
INFO Successfully connected to iboostesphome.local
[17:14:10][I][app:102]: ESPHome version 2023.8.1 compiled on Aug 19 2023, 14:16:52
[17:14:10][C][wifi:543]: WiFi:
[17:14:10][C][wifi:379]:   Local MAC: C4:5B:BE:4C:CB:12
[17:14:10][C][wifi:380]:   SSID: [redacted]
[17:14:10][C][wifi:381]:   IP Address: 192.168.1.173
[17:14:10][C][wifi:382]:   BSSID: [redacted]
[17:14:10][C][wifi:384]:   Hostname: 'iboostesphome'
[17:14:10][C][wifi:386]:   Signal strength: -74 dB ▂▄▆█
[17:14:10][C][wifi:390]:   Channel: 11
[17:14:10][C][wifi:391]:   Subnet: 255.255.255.0
[17:14:10][C][wifi:392]:   Gateway: 192.168.1.1
[17:14:10][C][wifi:393]:   DNS1: 192.168.1.1
[17:14:10][C][wifi:394]:   DNS2: 0.0.0.0
[17:14:10][C][logger:301]: Logger:
[17:14:10][C][logger:302]:   Level: DEBUG
[17:14:10][C][logger:303]:   Log Baud Rate: 115200
[17:14:10][C][logger:305]:   Hardware UART: UART0
[17:14:10][C][template.number:050]: Template Number 'iBoost Manual Boost Time'
[17:14:10][C][template.number:050]:   Icon: 'mdi:solar-power'
[17:14:10][C][template.number:050]:   Unit of Measurement: 'Minutes'
[17:14:10][C][template.number:051]:   Optimistic: YES
[17:14:10][C][template.number:052]:   Update Interval: 60.0s
[17:14:10][C][captive_portal:088]: Captive Portal:
[17:14:10][C][mdns:112]: mDNS:
[17:14:10][C][mdns:113]:   Hostname: iboostesphome
[17:14:10][C][ota:093]: Over-The-Air Updates:
[17:14:10][C][ota:094]:   Address: iboostesphome.local:8266
[17:14:10][C][ota:097]:   Using Password.
[17:14:10][C][api:138]: API Server:
[17:14:10][C][api:139]:   Address: iboostesphome.local:6053
[17:14:10][C][api:141]:   Using noise encryption: YES
[17:15:25][I][ota:113]: Boot seems successful, resetting boot loop counter.

It just sits here, no mention of SPI, radios etc.... anyone else seeing this?
@no1knows no1knows mentioned this issue Aug 19, 2023
Closed
@JNSwanson
Copy link
Owner

You did update the network name and password in the yaml file?

@no1knows no1knows mentioned this issue Aug 21, 2023
Closed
@no1knows
Copy link
Author

Thanks, I did. I also tried to do a fresh update in Home Assistant per the issue above, which works. It still doesn't seem to kick off any radio-related stuff:

INFO ESPHome 2023.8.1
INFO Reading configuration /config/esphome/iBoost.yaml...
INFO Generating C++ source...
INFO Compiling app...
Processing iboostesphome (board: d1_mini; framework: arduino; platform: platformio/espressif8266@3.2.0)
--------------------------------------------------------------------------------
HARDWARE: ESP8266 80MHz, 80KB RAM, 4MB Flash
Dependency Graph
|-- ESPAsyncTCP-esphome @ 1.2.3
|-- SPI @ 1.0
|-- ESPAsyncWebServer-esphome @ 2.1.0
|-- DNSServer @ 1.1.1
|-- ESP8266WiFi @ 1.0
|-- ESP8266mDNS @ 1.2
|-- noise-c @ 0.1.4
Compiling /data/iboostesphome/.pioenvs/iboostesphome/src/CC1101_RFx.cpp.o
Linking /data/iboostesphome/.pioenvs/iboostesphome/firmware.elf
RAM:   [====      ]  42.7% (used 34988 bytes from 81920 bytes)
Flash: [=====     ]  48.5% (used 506405 bytes from 1044464 bytes)
Building /data/iboostesphome/.pioenvs/iboostesphome/firmware.bin
esp8266_copy_factory_bin(["/data/iboostesphome/.pioenvs/iboostesphome/firmware.bin"], ["/data/iboostesphome/.pioenvs/iboostesphome/firmware.elf"])
========================= [SUCCESS] Took 29.12 seconds =========================
INFO Successfully compiled program.
INFO Resolving IP address of iboostesphome.local
INFO  -> 192.168.1.173
INFO Uploading /data/iboostesphome/.pioenvs/iboostesphome/firmware.bin (510560 bytes)
INFO Compressed to 355828 bytes
Uploading: [============================================================] 100% Done...

INFO Waiting for result...
INFO OTA successful
INFO Successfully uploaded program.
INFO Starting log output from iboostesphome.local using esphome API
WARNING Can't connect to ESPHome API for iboostesphome.local: Error resolving IP address: [Errno -5] No address associated with hostname (APIConnectionError)
INFO Trying to connect to iboostesphome.local in the background
INFO Successfully connected to iboostesphome.local
[07:53:14][I][app:102]: ESPHome version 2023.8.1 compiled on Aug 19 2023, 14:04:48
[07:53:14][C][wifi:543]: WiFi:
[07:53:14][C][wifi:379]:   Local MAC: C4:5B:BE:4C:CB:12
[07:53:14][C][wifi:380]:   SSID: [redacted]
[07:53:14][C][wifi:381]:   IP Address: 192.168.1.173
[07:53:14][C][wifi:382]:   BSSID: [redacted]
[07:53:14][C][wifi:384]:   Hostname: 'iboostesphome'
[07:53:14][C][wifi:386]:   Signal strength: -75 dB ▂▄▆█
[07:53:14][C][wifi:390]:   Channel: 1
[07:53:14][C][wifi:391]:   Subnet: 255.255.255.0
[07:53:14][C][wifi:392]:   Gateway: 192.168.1.1
[07:53:14][C][wifi:393]:   DNS1: 192.168.1.1
[07:53:14][C][wifi:394]:   DNS2: 0.0.0.0
[07:53:14][C][logger:301]: Logger:
[07:53:14][C][logger:302]:   Level: DEBUG
[07:53:14][C][logger:303]:   Log Baud Rate: 115200
[07:53:14][C][logger:305]:   Hardware UART: UART0
[07:53:14][C][template.number:050]: Template Number 'iBoost Manual Boost Time'
[07:53:14][C][template.number:050]:   Icon: 'mdi:solar-power'
[07:53:14][C][template.number:050]:   Unit of Measurement: 'Minutes'
[07:53:14][C][template.number:051]:   Optimistic: YES
[07:53:14][C][template.number:052]:   Update Interval: 60.0s
[07:53:14][C][captive_portal:088]: Captive Portal:
[07:53:14][C][mdns:112]: mDNS:
[07:53:14][C][mdns:113]:   Hostname: iboostesphome
[07:53:14][C][ota:093]: Over-The-Air Updates:
[07:53:14][C][ota:094]:   Address: iboostesphome.local:8266
[07:53:14][C][ota:097]:   Using Password.
[07:53:14][C][api:138]: API Server:
[07:53:14][C][api:139]:   Address: iboostesphome.local:6053
[07:53:14][C][api:141]:   Using noise encryption: YES
[07:53:29][D][api:102]: Accepted 192.168.1.99
[07:53:29][W][component:204]: Component api took a long time for an operation (0.29 s).
[07:53:29][W][component:205]: Components should block for at most 20-30ms.
[07:53:30][D][api.connection:1031]: Home Assistant 2023.8.3 (192.168.1.99): Connected successfully
[07:58:03][I][ota:113]: Boot seems successful, resetting boot loop counter.

@JNSwanson
Copy link
Owner

I compiled form the command line (windows) using Version: 2023.6.5 and it works ok.

@no1knows
Copy link
Author

Thanks! Turns out it was just a logging issue - it works fine now that I've turned the iBoost on and it has begun transmitting, but with the iBoost off the esp wasn't showing the radio-related log entries that the first version did, so I assumed there was an issue. (I tend to leave the iBoost off until my solar batteries are nearly full to avoid it triggering unnecessarily).

There's still a repeating error referring to an unknown component (any ideas what might be causing that?), but doesn't seem to impact operation:

INFO ESPHome 2023.8.2
INFO Reading configuration /config/esphome/iBoost.yaml...
INFO Starting log output from iboostesphome.local using esphome API
INFO Successfully connected to iboostesphome.local
[09:40:58][I][app:102]: ESPHome version 2023.8.2 compiled on Aug 21 2023, 23:12:45
[09:40:58][C][wifi:543]: WiFi:
[09:40:58][C][wifi:379]:   Local MAC: C4:5B:BE:4C:CB:12
[09:40:58][C][wifi:380]:   SSID: [redacted]
[09:40:58][C][wifi:381]:   IP Address: 192.168.1.173
[09:40:58][C][wifi:382]:   BSSID: [redacted]
[09:40:58][C][wifi:384]:   Hostname: 'iboostesphome'
[09:40:58][C][wifi:386]:   Signal strength: -91 dB ▂▄▆█
[09:40:58][C][wifi:390]:   Channel: 1
[09:40:58][C][wifi:391]:   Subnet: 255.255.255.0
[09:40:58][C][wifi:392]:   Gateway: 192.168.1.1
[09:40:58][C][wifi:393]:   DNS1: 192.168.1.1
[09:40:58][C][wifi:394]:   DNS2: 0.0.0.0
[09:40:58][C][logger:301]: Logger:
[09:40:58][C][logger:302]:   Level: DEBUG
[09:40:58][C][logger:303]:   Log Baud Rate: 115200
[09:40:58][C][logger:305]:   Hardware UART: UART0
[09:40:58][C][template.number:050]: Template Number 'iBoost Manual Boost Time'
[09:40:58][C][template.number:050]:   Icon: 'mdi:solar-power'
[09:40:58][C][template.number:050]:   Unit of Measurement: 'Minutes'
[09:40:58][C][template.number:051]:   Optimistic: YES
[09:40:58][C][template.number:052]:   Update Interval: 60.0s
[09:40:58][C][captive_portal:088]: Captive Portal:
[09:40:58][C][mdns:112]: mDNS:
[09:40:58][C][mdns:113]:   Hostname: iboostesphome
[09:40:58][C][ota:093]: Over-The-Air Updates:
[09:40:58][C][ota:094]:   Address: iboostesphome.local:8266
[09:40:58][C][ota:097]:   Using Password.
[09:40:58][C][api:138]: API Server:
[09:40:58][C][api:139]:   Address: iboostesphome.local:6053
[09:40:58][C][api:141]:   Using noise encryption: YES
[09:41:04][D][text_sensor:064]: 'iBoost Mode': Sending state 'Water Heating OFF'
[09:41:04][D][text_sensor:064]: 'iBoost Warn': Sending state ''
[09:41:04][D][sensor:093]: 'iBoost Import': Sending state -34.00000 W with 0 decimals of accuracy
[09:41:04][D][sensor:093]: 'iBoost Power': Sending state 0.00000 W with 0 decimals of accuracy
[09:41:04][D][sensor:093]: 'iBoost Today': Sending state 12.00000 Wh with 0 decimals of accuracy
[09:41:04][D][sensor:093]: 'iBoost Yesterday': Sending state 0.00000 Wh with 0 decimals of accuracy
[09:41:04][D][sensor:093]: 'iBoost Last 7 Days': Sending state 2158.00000 Wh with 0 decimals of accuracy
[09:41:04][D][sensor:093]: 'iBoost Boost Time Remaining': Sending state 0.00000 Min with 0 decimals of accuracy
[09:41:04][W][component:204]: Component <unknown> took a long time for an operation (0.08 s).
[09:41:04][W][component:205]: Components should block for at most 20-30ms.
[09:41:14][D][text_sensor:064]: 'iBoost Mode': Sending state 'Water Heating OFF'
[09:41:14][D][text_sensor:064]: 'iBoost Warn': Sending state ''
[09:41:14][D][sensor:093]: 'iBoost Import': Sending state 67.00000 W with 0 decimals of accuracy
[09:41:14][D][sensor:093]: 'iBoost Power': Sending state 0.00000 W with 0 decimals of accuracy
[09:41:14][D][sensor:093]: 'iBoost Today': Sending state 12.00000 Wh with 0 decimals of accuracy
[09:41:14][D][sensor:093]: 'iBoost Yesterday': Sending state 0.00000 Wh with 0 decimals of accuracy
[09:41:14][D][sensor:093]: 'iBoost Last 7 Days': Sending state 2158.00000 Wh with 0 decimals of accuracy
[09:41:14][D][sensor:093]: 'iBoost Last 28 days': Sending state 19953.00000 Wh with 0 decimals of accuracy
[09:41:14][D][sensor:093]: 'iBoost Boost Time Remaining': Sending state 0.00000 Min with 0 decimals of accuracy
[09:41:14][W][component:204]: Component <unknown> took a long time for an operation (0.09 s).
[09:41:14][W][component:205]: Components should block for at most 20-30ms.
[09:41:35][D][text_sensor:064]: 'iBoost Mode': Sending state 'Water Heating OFF'
[09:41:35][D][text_sensor:064]: 'iBoost Warn': Sending state ''
[09:41:35][D][sensor:093]: 'iBoost Import': Sending state -81.00000 W with 0 decimals of accuracy
[09:41:35][D][sensor:093]: 'iBoost Power': Sending state 43.00000 W with 0 decimals of accuracy
[09:41:35][D][sensor:093]: 'iBoost Today': Sending state 12.00000 Wh with 0 decimals of accuracy
[09:41:35][D][sensor:093]: 'iBoost Yesterday': Sending state 0.00000 Wh with 0 decimals of accuracy
[09:41:35][D][sensor:093]: 'iBoost Last 7 Days': Sending state 2158.00000 Wh with 0 decimals of accuracy
[09:41:35][D][sensor:093]: 'iBoost Last 28 days': Sending state 19953.00000 Wh with 0 decimals of accuracy
[09:41:35][D][sensor:093]: 'iBoost Boost Time Remaining': Sending state 0.00000 Min with 0 decimals of accuracy
[09:41:35][W][component:204]: Component <unknown> took a long time for an operation (0.09 s).
[09:41:35][W][component:205]: Components should block for at most 20-30ms.

@no1knows no1knows changed the title New version not working? Component <unknown> took a long time for an operation (0.08 s). Aug 26, 2023
@jfdawson
Copy link

I'm also seeing the "took a long time message".
Is it the speed of the SPI? If so can anyone point me to where I can adjust the SPI speed?
I saw similar behaviour with an I2C OLED display, where increasing the I2C speed was sufficient to solve the problem.
I guess the final question would be: does it matter ?

@srchild
Copy link

srchild commented Apr 12, 2024

I'm also seeing Component took a long time for an operation (0.11s).

I've ignored it because everything is working OK

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
4 participants
@no1knows @jfdawson @JNSwanson @srchild