search

home-assistant / core

:house_with_garden: Open source home automation that puts local control and privacy first.
https://www.home-assistant.io
Apache License 2.0
71.85k stars 30.1k forks source link

Unable to start after upgrade 2022.8.0 #76178

Closed lionslair closed 2 years ago

lionslair commented 2 years ago

The problem

Upgrade runs through and when the system tries to start it exits with fail

4 07:52:32 home-assistant.service: Main process exited, code=exited, status=1/FAILURE 4 07:52:32 systemd[1]: home-assistant.service: Failed with result 'exit-code'.

What version of Home Assistant Core has the issue?

2022.8.0

What was the last working version of Home Assistant Core?

2022.7.6

What type of installation are you running?

Home Assistant Core

Integration causing the issue

N/A

Link to integration documentation on our website

https://www.home-assistant.io/installation/linux#install-home-assistant-core

Diagnostics information

No response

Example YAML snippet

No response

Anything in the logs that might be useful for us?

I do have hacs installed. 

2022-08-04 07:55:02 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-08-04 07:55:02 WARNING (SyncWorker_1) [homeassistant.loader] We found a custom integration bureau_of_meteorology 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-08-04 07:55:02 WARNING (SyncWorker_1) [homeassistant.loader] We found a custom integration edgeos 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

Additional information

Rolling back to 2022.7.6 works fine

RoboMagus commented 2 years ago

Could you please provide some more logging? From HA and system level. With the information currently provided there's not much to look for.

lionslair commented 2 years ago

Could you please provide some more logging? From HA and system level. With the information currently provided there's not much to look for.

Is there something I cam turn on?

I am using an ansible script that stops removes reinstalls my core installation. all is fine it just fails to start with

4 07:52:32 home-assistant.service: Main process exited, code=exited, status=1/FAILURE 4 07:52:32 systemd[1]: home-assistant.service: Failed with result 'exit-code'.

anything I can turn on to debug?

lionslair commented 2 years ago

No extra logs `Aug 4 16:26:33 llserver ansible-ansible.legacy.copy: Invoked with src=/home/ansible/.ansible/tmp/ansible-tmp-1659601594.0145319-271878-265134117469397/source dest=/etc/systemd/system/home-assistant.service mode=None follow=False _original_basename=home-assistant.service.j2 checksum=53e93ce41e2bbbd51acdead1b48d966ac80fe70e backup=False force=True unsafe_writes=False content=NOT_LOGGING_PARAMETER validate=None directory_mode=None remote_src=None local_follow=None owner=None group=None seuser=None serole=None selevel=None setype=None attributes=None Aug 4 16:26:34 llserver ansible-ansible.builtin.systemd: Invoked with daemon_reload=True daemon_reexec=False scope=system no_block=False name=None state=None enabled=None force=None masked=None Aug 4 16:26:34 llserver systemd[1]: Reloading. Aug 4 16:26:35 llserver systemd[1]: nut-monitor.service: Supervising process 1186 which is not our child. We'll most likely not notice when it exits. Aug 4 16:26:35 llserver ansible-ansible.builtin.systemd: Invoked with name=home-assistant state=started daemon_reload=False daemon_reexec=False scope=system no_block=False enabled=None force=None masked=None Aug 4 16:26:35 llserver systemd[1]: Started Home Assistant venv. tail: 'home-assistant.log' has become inaccessible: No such file or directory tail: 'home-assistant.log' has appeared; following new file Aug 4 16:26:37 llserver hass[1697006]: 2022-08-04 16:26:37.036 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

==> home-assistant.log <== 2022-08-04 16:26:37.036 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-08-04 16:26:37.040 WARNING (SyncWorker_0) [homeassistant.loader] We found a custom integration bureau_of_meteorology 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

==> /var/log/syslog <== Aug 4 16:26:37 llserver hass[1697006]: 2022-08-04 16:26:37.040 WARNING (SyncWorker_0) [homeassistant.loader] We found a custom integration bureau_of_meteorology 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 Aug 4 16:26:37 llserver hass[1697006]: 2022-08-04 16:26:37.042 WARNING (SyncWorker_0) [homeassistant.loader] We found a custom integration edgeos 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

==> home-assistant.log <== 2022-08-04 16:26:37.042 WARNING (SyncWorker_0) [homeassistant.loader] We found a custom integration edgeos 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

==> /var/log/syslog <== Aug 4 16:26:41 llserver systemd[1]: home-assistant.service: Main process exited, code=exited, status=1/FAILURE Aug 4 16:26:41 llserver systemd[1]: home-assistant.service: Failed with result 'exit-code'. `

lionslair commented 2 years ago

appears installed

`root@llserver:/srv/homeassistant/.virtualenv/bin# ./hass --version 2022.8.0

`

Run manually same thing.

root@llserver:/srv/homeassistant/.virtualenv/bin# ./hass -c /srv/homeassistant/ 2022-08-04 16:31:12.913 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-08-04 16:31:12.914 WARNING (SyncWorker_0) [homeassistant.loader] We found a custom integration bureau_of_meteorology 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-08-04 16:31:12.915 WARNING (SyncWorker_0) [homeassistant.loader] We found a custom integration edgeos 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

lionslair commented 2 years ago

I have been trying to find something that is telling me why but the only information I have is this

`==> syslog <== Aug 5 16:14:26 llserver systemd[1]: Started Home Assistant venv. tail: '/srv/homeassistant/home-assistant.log' has become inaccessible: No such file or directory tail: '/srv/homeassistant/home-assistant.log' has appeared; following new file Aug 5 16:14:27 llserver hass[2802110]: 2022-08-05 16:14:27.203 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

==> /srv/homeassistant/home-assistant.log <== 2022-08-05 16:14:27.203 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-08-05 16:14:27.204 WARNING (SyncWorker_0) [homeassistant.loader] We found a custom integration bureau_of_meteorology 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-08-05 16:14:27.204 WARNING (SyncWorker_0) [homeassistant.loader] We found a custom integration edgeos 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

==> syslog <== Aug 5 16:14:27 hass[2802110]: 2022-08-05 16:14:27.204 WARNING (SyncWorker_0) [homeassistant.loader] We found a custom integration bureau_of_meteorology 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 Aug 5 16:14:27 hass[2802110]: 2022-08-05 16:14:27.204 WARNING (SyncWorker_0) [homeassistant.loader] We found a custom integration edgeos 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 Aug 5 16:14:27 systemd[1]: home-assistant.service: Main process exited, code=exited, status=1/FAILURE Aug 5 16:14:27 systemd[1]: home-assistant.service: Failed with result 'exit-code'. `

this is my systemd loader

[Unit]
Description=Home Assistant venv
After=network-online.target

[Service]
Type=simple
ExecStart=/srv/homeassistant/.virtualenv/bin/hass -c /srv/homeassistant

[Install]
WantedBy=multi-user.target

All seems to install fine

.virtualenv/bin# ./hass --version
2022.8.1

Just will not start. Can still roll back to 2022.7.6 any time without issue.

lionslair commented 2 years ago

ok I just tried with debug mode

root@llserver:/srv/homeassistant/.virtualenv/bin# ./hass --debug
2022-08-05 16:18:02.150 ERROR (MainThread) [root] Uncaught exception
Traceback (most recent call last):
  File "/srv/homeassistant/.virtualenv/bin/./hass", line 8, in <module>
    sys.exit(main())
  File "/srv/homeassistant/.virtualenv/lib/python3.10/site-packages/homeassistant/__main__.py", line 191, in main
    exit_code = runner.run(runtime_conf)
  File "/srv/homeassistant/.virtualenv/lib/python3.10/site-packages/homeassistant/runner.py", line 119, in run
    return loop.run_until_complete(setup_and_run_hass(runtime_config))
  File "/usr/lib/python3.10/asyncio/base_events.py", line 646, in run_until_complete
    return future.result()
  File "/srv/homeassistant/.virtualenv/lib/python3.10/site-packages/homeassistant/runner.py", line 101, in setup_and_run_hass
    hass = await bootstrap.async_setup_hass(runtime_config)
  File "/srv/homeassistant/.virtualenv/lib/python3.10/site-packages/homeassistant/bootstrap.py", line 143, in async_setup_hass
    await async_from_config_dict(config_dict, hass) is not None
  File "/srv/homeassistant/.virtualenv/lib/python3.10/site-packages/homeassistant/bootstrap.py", line 256, in async_from_config_dict
    await _async_set_up_integrations(hass, config)
  File "/srv/homeassistant/.virtualenv/lib/python3.10/site-packages/homeassistant/bootstrap.py", line 532, in _async_set_up_integrations
    recorder.async_initialize_recorder(hass)
  File "/srv/homeassistant/.virtualenv/lib/python3.10/site-packages/homeassistant/helpers/recorder.py", line 22, in async_initialize_recorder
    from homeassistant.components.recorder import const, models
  File "/srv/homeassistant/.virtualenv/lib/python3.10/site-packages/homeassistant/components/recorder/__init__.py", line 23, in <module>
    from . import statistics, websocket_api
  File "/srv/homeassistant/.virtualenv/lib/python3.10/site-packages/homeassistant/components/recorder/statistics.py", line 17, in <module>
    from sqlalchemy import bindparam, func, lambda_stmt, select
ModuleNotFoundError: No module named 'sqlalchemy'
RoboMagus commented 2 years ago

Home Assistant not having write access to the logfile / database came to mind before I saw your update with the logging from debug mode. But that apparently is not it.

It seems like in the 2022.8.x update something happened to your python environment. The ModuleNotFoundError: No module named 'sqlalchemy' hints at a dependency problem, but this module was already being used in older versions of HA as well...

Could you run pip check in your python environment to see if there are other broken dependencies? To fix the environment any missing dependencies can be installed using pip install <module-name>. However as far as the cause of this issue I am unsure.

Are you running your setup on a Raspberry Pi with SDcard by any chance?

lionslair commented 2 years ago

No. I am running thank you for replying.

I am running on a HP ProLiant MicroServer 4GB ram with SSD.

I have added sqlalchemy to my ansible install to make sure its there now.

I have found if I run 

/srv/homeassistant/.virtualenv/bin# ./hass --script check_config

I get 

root@llserver:/srv/homeassistant/.virtualenv/bin# ./hass --script check_config
INFO:homeassistant.util.package:Attempting install of colorlog==6.6.0
Testing configuration at /root/.homeassistant
INFO:homeassistant.util.package:Attempting install of aiohttp_cors==0.7.0
INFO:homeassistant.util.package:Attempting install of bluetooth-adapters==0.1.3
INFO:homeassistant.util.package:Attempting install of hass-nabucasa==0.54.1
INFO:homeassistant.util.package:Attempting install of scapy==2.4.5
INFO:homeassistant.util.package:Attempting install of aiodiscover==1.4.11
INFO:homeassistant.util.package:Attempting install of home-assistant-frontend==20220802.0
INFO:homeassistant.util.package:Attempting install of PyNaCl==1.5.0
INFO:homeassistant.util.package:Attempting install of async-upnp-client==0.31.2
INFO:homeassistant.util.package:Attempting install of sqlalchemy==1.4.38
INFO:homeassistant.util.package:Attempting install of fnvhash==0.1.0
INFO:homeassistant.util.package:Attempting install of pillow==9.2.0
INFO:homeassistant.util.package:Attempting install of zeroconf==0.38.7
INFO:homeassistant.util.package:Attempting install of pyudev==0.23.2
INFO:homeassistant.util.package:Attempting install of pyserial==3.5
INFO:homeassistant.util.package:Attempting install of PyTurboJPEG==1.6.7
INFO:homeassistant.util.package:Attempting install of mutagen==1.45.1
INFO:homeassistant.util.package:Attempting install of gTTS==2.2.4

adding 

ExecStart=/srv/homeassistant/.virtualenv/bin/hass -c /srv/homeassistant --script check_config

exactly 

 --script check_config

at the end of my systemd script seems to have made it start. the output was

Aug  5 17:05:09 llserver hass[2850441]: #033[1mTesting configuration at /srv/homeassistant#033[0m
Aug  5 17:05:09 llserver hass[2850441]: INFO:homeassistant.util.package:Attempting install of aiohttp_cors==0.7.0
Aug  5 17:05:11 llserver hass[2850441]: INFO:homeassistant.util.package:Attempting install of bluetooth-adapters==0.1.3
Aug  5 17:05:13 llserver hass[2850441]: INFO:homeassistant.util.package:Attempting install of hass-nabucasa==0.54.1
Aug  5 17:05:23 llserver hass[2850441]: INFO:homeassistant.util.package:Attempting install of scapy==2.4.5
Aug  5 17:05:27 llserver hass[2850441]: INFO:homeassistant.util.package:Attempting install of aiodiscover==1.4.11
Aug  5 17:05:31 llserver hass[2850441]: INFO:homeassistant.util.package:Attempting install of home-assistant-frontend==20220802.0
Aug  5 17:05:37 llserver hass[2850441]: INFO:homeassistant.util.package:Attempting install of PyNaCl==1.5.0
Aug  5 17:05:39 llserver hass[2850441]: INFO:homeassistant.util.package:Attempting install of async-upnp-client==0.31.2
Aug  5 17:05:42 llserver hass[2850441]: INFO:homeassistant.util.package:Attempting install of pyudev==0.23.2
Aug  5 17:05:44 llserver hass[2850441]: INFO:homeassistant.util.package:Attempting install of pyserial==3.5
Aug  5 17:05:46 llserver hass[2850441]: INFO:homeassistant.util.package:Attempting install of zeroconf==0.38.7
Aug  5 17:05:49 llserver hass[2850441]: INFO:homeassistant.util.package:Attempting install of sqlalchemy==1.4.38
Aug  5 17:05:54 llserver hass[2850441]: INFO:homeassistant.util.package:Attempting install of fnvhash==0.1.0
Aug  5 17:05:57 llserver hass[2850441]: INFO:homeassistant.util.package:Attempting install of pillow==9.2.0
Aug  5 17:06:00 llserver hass[2850441]: INFO:homeassistant.util.package:Attempting install of PyTurboJPEG==1.6.7
Aug  5 17:06:08 llserver hass[2850441]: INFO:homeassistant.util.package:Attempting install of wirelesstagpy==0.8.1
Aug  5 17:06:11 llserver hass[2850441]: INFO:homeassistant.util.package:Attempting install of mutagen==1.45.1
Aug  5 17:06:13 llserver hass[2850441]: INFO:homeassistant.util.package:Attempting install of gTTS==2.2.4

So I am missing a lot?

lionslair commented 2 years ago

Nope only the manual run worked this stopped on my next test. sigh

I can still keep rolling back to 2022.7.6 no issues. starts fine

danodemano commented 2 years ago

I'm going to throw a me too into this mainly so I get updates.

lionslair commented 2 years ago

I'm going to throw a me too into this mainly so I get updates.

Have you had the same issue?

danodemano commented 2 years ago

Yep, I haven't done the extend of testing you have since I haven't had the time. I landed here from a Google search. But I get that same "code=exited, status=1/FAILURE" pretty much immediately after starting with just the custom component warnings in the logs.

lionslair commented 2 years ago

Yep, I haven't done the extend of testing you have since I haven't had the time. I landed here from a Google search. But I get that same "code=exited, status=1/FAILURE" pretty much immediately after starting with just the custom component warnings in the logs.

I will try some more today. My guess it's something to do with new python libs or something within the release.

Will continue to post any thing more I manage to find

danodemano commented 2 years ago

Thanks for the info! If I can be of any help let me know. My weekends are usually hot garbage with house projects but I can play on Monday if needed. As of now my Monday is really light with meetings and whatnot. Appreciate it!!!

gudvinr commented 2 years ago

I also have same issue. I am running homeassistant from PYPI in venv inside docker and after updating HA installation in docker image to 2022.8 it crashes

lionslair commented 2 years ago

I have finally got this working on 2022.8.2

Like in my previous posts it seems that it was missing sqlalchemy, fnvhash within the virtual environment. Even though I did have them added to the host system.

This issue seems closely related. https://github.com/home-assistant/core/issues/76296

danodemano commented 2 years ago

For me it was just fnvhash that was missing, sqlalchemy was there. After installing it HA seems to be working as expected.