search

home-assistant / frontend

:lollipop: Frontend for Home Assistant
https://demo.home-assistant.io
Other
4.05k stars 2.77k forks source link

Fresh Install - invalid command: energy/get_prefs #11340

Closed tonydm closed 2 years ago

tonydm commented 2 years ago

Checklist

Describe the issue you are experiencing

Fresh install of HA using Proxmox 7.1-4, KVM/Proxmox (.qcow2). CPU: 4 Cores RAM: 2GB DISK: 32GB

Addons: Check Config ESPHome Node Red Studio Code Server

Log shows ERROR, not WARNING, therefore interpreted as critical.

2022-01-16 13:03:19 ERROR (MainThread) [homeassistant.components.websocket_api.http.connection] [140249835961792] Received invalid command: energy/get_prefs

configuration.yaml

No changes to default yaml files referenced in the default config
# Configure a default setup of Home Assistant (frontend, api, etc)
default_config:

# Text to speech
tts:
  - platform: google_translate

group: !include groups.yaml
automation: !include automations.yaml
script: !include scripts.yaml
scene: !include scenes.yaml

Describe the behavior you expected

Since I have a fresh install with minimal customization and zero changes to the "new" Energy tab/feature. I would not expect to see ERRORs specifically related to such in the log.

I've looked at https://github.com/home-assistant/frontend/pull/9763 but don't understand the comments made by ledeeus and balloob in the context if the issue being resolved, i.e. Why we see an ERROR vs WARNING or even INFO?

Steps to reproduce the issue

  1. No need to reproduce, it is generated all by itself as far as I can tell. There's nothing that I've configured/changed even related to Energy

What version of Home Assistant Core has the issue?

core-2021.12.9

What was the last working version of Home Assistant Core?

core-2021.12.9

In which browser are you experiencing the issue with?

Google Chrome 97.0.4692.71

Which operating system are you using to run this browser?

Pop!_OS 20.04 LTS \n \l

State of relevant entities

No response

Problem-relevant frontend configuration

No response

Javascript errors shown in your browser console/inspector

No response

Additional information

No response

spacegaier commented 2 years ago

Just glancing at the coding I can see two places, where the call to energy/get_prefs is made and if it results in an "not_found" exception this is the indicator to show e.g. the energy setup dialog. That might be the error you see in the log. But that is just a guess at this point.

tonydm commented 2 years ago

Thank you, but I don't think I understand the point of the ERROR in the logs on a new install in the first place. And what is it that I'm to understand "indicator to show... the energy setup dialog"? What dialog? There's the Energy Dashboard... that hasn't been set up. Is that the Dialog you to which you refer? I again ask why is there an ERROR on a new install that I have to FIX? I've followed the link "More information on how to get started.". I then followed the link to Marcel Zuidwijk's website to learn more about the SlimmeLezer+ product to connect directly to the P1 port of the meter. I don't know yet if I even have a meter with a P1 port. And, of course, there are other products to tap/monitor current. Am I to understand that this new Energy Dashboard feature requires one to purchase and install additional sensors in order to resolve the ERROR? I'm not sure that makes sense to me. Why not provide the Energy monitor as an Integration or something that doesn't cause/force one to resolve ERRORs? I'm harping on this because I don't see the reason one has to chase down an unnecessary error that's really not an error at all. Or am I completely the one man out that is completely off base?

Thank you

dennismeng commented 2 years ago

I have the exact same error on a fresh installation of HA OS. I haven't configured anything Energy related (nor can I, as I cannot connect to my power provider/meter).

spacegaier commented 2 years ago

@balloob @bramkragten Can you shed some light onto the designed process here?

bramkragten commented 2 years ago

We should not call energy/get_prefs before the energy integration is loaded, "not_found" will only be returned if the energy integration is there. Let me check where it can do this...

bramkragten commented 2 years ago

When do you get this error? When just visiting the main Lovelace dashboard or somewhere else?

tonydm commented 2 years ago

@bramkragten Fresh install, immediately the ERROR is found in the home-assistant log. I haven't moved forward with any additional configuration (i.e. my goal was to migrate from one server to another and upgrade in the process). Looking at it today based on the new conversation today, I don't see any new errors. No error displayed in the GUI, just the logs. But as a SysAdmin, DevOpts, Network Engineer by trade, I'm always going to investigate logs to be familiar

bramkragten commented 2 years ago

It definitely is not a critical error, as in, it is save to ignore. But would like to fix it anyway.

tonydm commented 2 years ago

@bramkragten Perfect... as Home Assistant is really a tinkerer's paradise, most of us look under the covers and when an ERROR shows up, it raises alarm bells. Thank you for looking at this and my appreciation for your work on the project.

emontnemery commented 2 years ago

@tonydm could you try to reproduce this again, with these logs enabled:

logger:                         
   default: info                
   logs:                        
     homeassistant.core: debug  
     homeassistant.loader: debug
     homeassistant.setup: debug
tonydm commented 2 years ago

@emontnemery Super appreciate the effort to resolve but it's not a matter of reproducing... As I indicated, a fresh install and a look at the logs revealed the ERROR(s) in question. Additionally, the error was/is generated by the system BEFORE one can log in and update the configuration.yml file with the requested logging/debugging statements so it's not possible, at least in my curcumstance, to get ahead of the error. Since this is a supported installation using the https://www.home-assistant.io/installation/alternative downloads method, in order to modify the config you can't ssh into the server/host (you only have the ha> cli to work with), one has to Onboard first, then install either VSCode Server, File Editor, or Samba Add-on.

With that said, I installed as another VM, onboarded, installed vscode and made the changes requested. However, the Home Assistant version (qcow2 file) is now at v7.3 whereas the version I originally installed was v7.2 and reported the ERROR. I don't see the ERROR with energy/get_prefs in the log for this test install. I also stepped through the Energy setup, which I hadn't done before as I don't have anything setup yet for relative stats. Again, I don't see the `energy/get_prefs' ERROR. I can go back and pull down the v7.2 and install again, but is there a chance the issue was resolved in v7.3?

bramkragten commented 2 years ago

It probably is a race condition, that happens sometimes but not always

emontnemery commented 2 years ago

Yes, it's most likely a race. I've tried to provoke it by delaying setup of the energy integration in various ways, but with no luck.

@tonydm do you mean you only saw the error message a single time, on the fresh install?

tonydm commented 2 years ago

@emontnemery Yes. I was/am migrating from an unsupported Docker install (my personal preference) to a supported install. After I Onboared and looked at the logs, that's the first thing that popped out to me. It wasn't just one entry, I saw it several times. I should have done a better job of capturing ALL that data. But as I reported, another install via the KVM method (in this case HA v7.3) showed no errors.

dhover commented 2 years ago

Everytime after a restart of Home Assistant the error pops up twice:

2022-04-21 20:13:34 ERROR (MainThread) [homeassistant.components.websocket_api.http.connection] [140458920098064] Received invalid command: energy/get_prefs
2022-04-21 20:13:34 ERROR (MainThread) [homeassistant.components.websocket_api.http.connection] [140458920098064] Received invalid command: energy/get_prefs

Running HA core-2022.4.6

dhover commented 2 years ago 
2022-04-21 20:20:30 WARNING (SyncWorker_2) [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-04-21 20:20:30 WARNING (SyncWorker_1) [homeassistant.loader] We found a custom integration holidays 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-04-21 20:20:30 WARNING (SyncWorker_2) [homeassistant.loader] We found a custom integration nefiteasy 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-04-21 20:20:30 WARNING (SyncWorker_3) [homeassistant.loader] We found a custom integration weatherlink 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-04-21 20:20:30 WARNING (SyncWorker_0) [homeassistant.loader] We found a custom integration solaredge_modbus 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-04-21 20:20:30 WARNING (SyncWorker_1) [homeassistant.loader] We found a custom integration weatherflow 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-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=logger, service=set_default_level>
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=logger, service=set_level>
2022-04-21 20:20:31 INFO (MainThread) [homeassistant.setup] Setup of domain logger took 0.0 seconds
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=system_log>
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=logger>
2022-04-21 20:20:31 INFO (MainThread) [homeassistant.setup] Setup of domain recorder took 0.0 seconds
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=recorder>
2022-04-21 20:20:31 INFO (MainThread) [homeassistant.bootstrap] Setting up stage 1: {'onboarding', 'system_log', 'frontend', 'config', 'webhook', 'image', 'http', 'network', 'search', 'api', 'analytics', 'dhcp', 'diagnostics', 'hassio', 'zeroconf', 'auth', 'ssdp', 'cloud', 'person', 'websocket_api', 'lovelace', 'usb', 'device_automation'}
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.setup] Dependency onboarding will wait for dependencies ['analytics', 'auth', 'http', 'person']
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.setup] Dependency frontend will wait for dependencies ['api', 'auth', 'config', 'device_automation', 'diagnostics', 'http', 'lovelace', 'onboarding', 'search', 'websocket_api']
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.setup] Dependency config will wait for dependencies ['http']
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.setup] Dependency webhook will wait for dependencies ['http']
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.setup] Dependency image will wait for dependencies ['http']
2022-04-21 20:20:31 INFO (MainThread) [homeassistant.setup] Setting up http
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.setup] Dependency network will wait for dependencies ['websocket_api']
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.setup] Dependency search will wait for dependencies ['websocket_api']
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.setup] Dependency api will wait for dependencies ['http']
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.setup] Dependency analytics will wait for dependencies ['api', 'websocket_api']
2022-04-21 20:20:31 INFO (MainThread) [homeassistant.setup] Setting up dhcp
2022-04-21 20:20:31 INFO (MainThread) [homeassistant.setup] Setup of domain dhcp took 0.0 seconds
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.setup] Dependency diagnostics will wait for dependencies ['http']
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.setup] Dependency hassio will wait for dependencies ['http']
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.setup] Dependency zeroconf will wait for dependencies ['network', 'api']
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.setup] Dependency auth will wait for dependencies ['http']
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.setup] Dependency ssdp will wait for dependencies ['network']
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.setup] Dependency cloud will wait for dependencies ['http', 'webhook']
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.setup] Dependency person will wait for dependencies ['image']
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.setup] Dependency websocket_api will wait for dependencies ['http']
2022-04-21 20:20:31 INFO (MainThread) [homeassistant.setup] Setting up lovelace
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event panels_updated[L]>
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.setup] Dependency usb will wait for dependencies ['websocket_api']
2022-04-21 20:20:31 INFO (MainThread) [homeassistant.setup] Setting up device_automation
2022-04-21 20:20:31 INFO (MainThread) [homeassistant.setup] Setup of domain device_automation took 0.0 seconds
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=dhcp>
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=device_automation>
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event panels_updated[L]>
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event panels_updated[L]>
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event panels_updated[L]>
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event panels_updated[L]>
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event panels_updated[L]>
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event panels_updated[L]>
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event panels_updated[L]>
2022-04-21 20:20:31 INFO (MainThread) [homeassistant.setup] Setup of domain lovelace took 0.0 seconds
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=lovelace>
2022-04-21 20:20:31 INFO (MainThread) [homeassistant.setup] Setup of domain http took 0.1 seconds
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=http>
2022-04-21 20:20:31 INFO (MainThread) [homeassistant.setup] Setting up config
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event panels_updated[L]>
2022-04-21 20:20:31 INFO (MainThread) [homeassistant.setup] Setting up webhook
2022-04-21 20:20:31 INFO (MainThread) [homeassistant.setup] Setup of domain webhook took 0.0 seconds
2022-04-21 20:20:31 INFO (MainThread) [homeassistant.setup] Setting up image
2022-04-21 20:20:31 INFO (MainThread) [homeassistant.setup] Setting up api
2022-04-21 20:20:31 INFO (MainThread) [homeassistant.setup] Setup of domain api took 0.0 seconds
2022-04-21 20:20:31 INFO (MainThread) [homeassistant.setup] Setting up diagnostics
2022-04-21 20:20:31 INFO (MainThread) [homeassistant.setup] Setting up hassio
2022-04-21 20:20:31 INFO (MainThread) [homeassistant.setup] Setting up auth
2022-04-21 20:20:31 INFO (MainThread) [homeassistant.setup] Setup of domain auth took 0.0 seconds
2022-04-21 20:20:31 INFO (MainThread) [homeassistant.setup] Setting up websocket_api
2022-04-21 20:20:31 INFO (MainThread) [homeassistant.setup] Setup of domain websocket_api took 0.0 seconds
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=config.area_registry>
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=config.auth>
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=config.auth_provider_homeassistant>
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=config.automation>
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=config.config_entries>
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=config.core>
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=config.device_registry>
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=config.entity_registry>
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=config.script>
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=config.scene>
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=webhook>
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=api>
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=auth>
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=websocket_api>
2022-04-21 20:20:31 INFO (MainThread) [homeassistant.setup] Setup of domain config took 0.0 seconds
2022-04-21 20:20:31 INFO (MainThread) [homeassistant.setup] Setup of domain diagnostics took 0.0 seconds
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=config>
2022-04-21 20:20:31 INFO (MainThread) [homeassistant.setup] Setting up cloud
2022-04-21 20:20:31 INFO (MainThread) [homeassistant.setup] Setup of domain image took 0.2 seconds
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=diagnostics>
2022-04-21 20:20:31 INFO (MainThread) [homeassistant.setup] Setting up network
2022-04-21 20:20:31 INFO (MainThread) [homeassistant.setup] Setup of domain network took 0.0 seconds
2022-04-21 20:20:31 INFO (MainThread) [homeassistant.setup] Setting up search
2022-04-21 20:20:31 INFO (MainThread) [homeassistant.setup] Setup of domain search took 0.0 seconds
2022-04-21 20:20:31 INFO (MainThread) [homeassistant.setup] Setting up analytics
2022-04-21 20:20:31 INFO (MainThread) [homeassistant.setup] Setting up usb
2022-04-21 20:20:31 INFO (MainThread) [homeassistant.setup] Setup of domain usb took 0.0 seconds
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=image>
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=network>
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=search>
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=usb>
2022-04-21 20:20:31 INFO (MainThread) [homeassistant.setup] Setting up person
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=cloud, service=remote_connect>
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=cloud, service=remote_disconnect>
2022-04-21 20:20:31 INFO (MainThread) [homeassistant.setup] Setting up zeroconf
2022-04-21 20:20:31 INFO (MainThread) [homeassistant.setup] Setting up ssdp
2022-04-21 20:20:31 INFO (MainThread) [homeassistant.setup] Setup of domain ssdp took 0.0 seconds
2022-04-21 20:20:31 INFO (MainThread) [homeassistant.setup] Setup of domain analytics took 0.1 seconds
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=ssdp>
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=analytics>
2022-04-21 20:20:31 INFO (MainThread) [homeassistant.setup] Setup of domain cloud took 0.1 seconds
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=cloud>
2022-04-21 20:20:31 INFO (MainThread) [homeassistant.setup] Setup of domain zeroconf took 0.0 seconds
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=zeroconf>
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event panels_updated[L]>
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=person.xxx ....
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=person.xxx ....
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=person.xxx ....
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=person.xxx ....
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=person.xxx ....
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=person.xxx ....
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=person, service=reload>
2022-04-21 20:20:31 INFO (MainThread) [homeassistant.setup] Setup of domain person took 0.1 seconds
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=person>
2022-04-21 20:20:31 INFO (MainThread) [homeassistant.setup] Setting up onboarding
2022-04-21 20:20:31 INFO (MainThread) [homeassistant.helpers.storage] Migrating onboarding storage from 3.1 to 4.1
2022-04-21 20:20:31 INFO (MainThread) [homeassistant.setup] Setup of domain onboarding took 0.0 seconds
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=onboarding>
2022-04-21 20:20:31 INFO (MainThread) [homeassistant.setup] Setting up frontend
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event panels_updated[L]>
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event panels_updated[L]>
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=frontend, service=set_theme>
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=frontend, service=reload_themes>
2022-04-21 20:20:31 INFO (MainThread) [homeassistant.setup] Setup of domain frontend took 0.0 seconds
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=frontend>
2022-04-21 20:20:31 INFO (MainThread) [homeassistant.components.http] Now listening on port 8123
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=hassio, service=addon_start>
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=hassio, service=addon_stop>
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=hassio, service=addon_restart>
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=hassio, service=addon_update>
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=hassio, service=addon_stdin>
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=hassio, service=host_shutdown>
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=hassio, service=host_reboot>
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=hassio, service=backup_full>
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=hassio, service=backup_partial>
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=hassio, service=restore_full>
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=hassio, service=restore_partial>
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=homeassistant, service=stop>
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=homeassistant, service=restart>
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=homeassistant, service=check_config>
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event panels_updated[L]>
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event panels_updated[L]>
2022-04-21 20:20:31 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event panels_updated[L]>
2022-04-21 20:20:31 INFO (MainThread) [homeassistant.setup] Setup of domain hassio took 0.4 seconds
2022-04-21 20:20:33 ERROR (MainThread) [homeassistant.components.websocket_api.http.connection] [140330394237344] Received invalid command: energy/get_prefs
2022-04-21 20:20:33 ERROR (MainThread) [homeassistant.components.websocket_api.http.connection] [140330394237344] Received invalid command: energy/get_prefs
2022-04-21 20:20:33 ERROR (MainThread) [homeassistant.components.hassio.handler] /addons return code 500
2022-04-21 20:20:33 ERROR (MainThread) [homeassistant.components.hassio] Failed to to call /addons -
2022-04-21 20:20:33 ERROR (MainThread) [homeassistant.components.hassio.handler] /store return code 500
2022-04-21 20:20:33 ERROR (MainThread) [homeassistant.components.hassio] Failed to to call /store -
2022-04-21 20:20:39 INFO (MainThread) [homeassistant.setup] Setting up binary_sensor
2022-04-21 20:20:39 INFO (MainThread) [homeassistant.setup] Setup of domain binary_sensor took 0.0 seconds
2022-04-21 20:20:39 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=hassio>
2022-04-21 20:20:39 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=binary_sensor>
2022-04-21 20:20:39 INFO (SyncWorker_15) [homeassistant.loader] Loaded update from homeassistant.components.update
2022-04-21 20:20:39 INFO (MainThread) [homeassistant.setup] Setting up template
2022-04-21 20:20:39 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=template, service=reload>
2022-04-21 20:20:39 INFO (MainThread) [homeassistant.setup] Setup of domain template took 0.0 seconds
2022-04-21 20:20:39 INFO (MainThread) [homeassistant.components.binary_sensor] Setting up binary_sensor.hassio
2022-04-21 20:20:39 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event component_loaded[L]: component=template>
2022-04-21 20:20:40 INFO (SyncWorker_2) [homeassistant.loader] Loaded dsmr_reader from homeassistant.components.dsmr_reader
2022-04-21 20:20:40 INFO (MainThread) [homeassistant.setup] Setting up update
2022-04-21 20:20:40 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=update, service=install>
2022-04-21 20:20:40 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event service_registered[L]: domain=update, service=skip>
2022-04-21 20:20:40 INFO (MainThread) [homeassistant.setup] Setup of domain update took 0.0 seconds
dhover commented 2 years ago

After a number of restarts the error is gone!

dhover commented 2 years ago

Another restart and the error is back.

2022-04-21 22:38:41 ERROR (MainThread) [homeassistant.components.websocket_api.http.connection] [140179998490976] Received invalid command: energy/info
2022-04-21 22:38:41 ERROR (MainThread) [homeassistant.components.websocket_api.http.connection] [140179998490976] Received invalid command: energy/info
SimonFili commented 2 years ago

I can confirm, "fresh" install and I get it in the logs. I just installed some basics add-ons and looking at the logs to ensure I got everything right:

Logger: homeassistant.components.websocket_api.http.connection Source: components/websocket_api/connection.py:96 Integration: Home Assistant WebSocket API (documentation, issues) First occurred: 6:57:13 AM (1 occurrences) Last logged: 6:57:13 AM

[139746880588384] Received invalid command: energy/get_prefs

I installed it yesterday on a clean x64 PC.

github-actions[bot] commented 2 years ago

There hasn't been any activity on this issue recently. Due to the high number of incoming GitHub notifications, we have to clean some of the old issues, as many of them have already been resolved with the latest updates. Please make sure to update to the latest Home Assistant version and check if that solves the issue. Let us know if that works for you by adding a comment 👍 This issue has now been marked as stale and will be closed if no further activity occurs. Thank you for your contributions.