Systemd Startup Fails

I’m having a bit of a dilemma here… I have been running my system for a little over a year initially using SQLite and later MariaDB. I recently switched back to using SQLite (new DB) while I worked on upgrading MariaDB (as part of a project to replicate it to Amazon RDS). I’m not sure what happened, but since I started this little side project I can’t seem to get HA to start using systemd. Or more accurately it starts and then shuts down without an error after completing initialization. If I jump to a shell running as the homeassistant user (also, via root as sudo, but running as homeassistant makes more sense, but I digress) I can start HA at the command line using the exact command that is is the systemd file:

/srv/homeassistant/bin/python3 /srv/homeassistant/bin/hass -c /home/homeassistant/.homeassistant

Yet the systemd startup via systemctl doesn’t work. (i.e. starts and stops) My systemd file which had been working previously:

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

[Service]
Type=simple
User=homeassistant
Group=nogroup

ExecStart=/srv/homeassistant/bin/hass -c "/home/homeassistant/.homeassistant"

[Install]
WantedBy=multi-user.target

Has anyone ever seen anything like this? I’m stumped as things seem fine, but the startup just dies via systemd, but works interactively via the command line. ???

Can you add the complete output of systemctl status <your job name>

The output often includes useful clues.

Right after starting:

$ sudo systemctl status [email protected]
? [email protected] - Home Assistant
   Loaded: loaded (/etc/systemd/system/[email protected]; enabled; vendor preset: enabled)
   Active: active (running) since Mon 2020-02-10 06:57:25 EST; 8s ago
 Main PID: 13329 (hass)
   CGroup: /system.slice/system-home\x2dassistant.slice/[email protected]
           +-13329 /srv/homeassistant/bin/python3 /srv/homeassistant/bin/hass -c /home/homeassistant/.homeassistant

Feb 10 06:57:34 odroid hass[13329]:     platform = await async_prepare_setup_platform(
Feb 10 06:57:34 odroid hass[13329]:   File "/srv/homeassistant/lib/python3.8/site-packages/homeassistant/setup.py", line 229, in async_prepare_setup_platform
Feb 10 06:57:34 odroid hass[13329]:     integration = await loader.async_get_integration(hass, platform_name)
Feb 10 06:57:34 odroid hass[13329]:   File "/srv/homeassistant/lib/python3.8/site-packages/homeassistant/loader.py", line 310, in async_get_integration
Feb 10 06:57:34 odroid hass[13329]:     integration = await hass.async_add_executor_job(
Feb 10 06:57:34 odroid hass[13329]:   File "/usr/lib/python3.8/concurrent/futures/thread.py", line 57, in run
Feb 10 06:57:34 odroid hass[13329]:     result = self.fn(*self.args, **self.kwargs)
Feb 10 06:57:34 odroid hass[13329]:   File "/srv/homeassistant/lib/python3.8/site-packages/homeassistant/loader.py", line 154, in resolve_from_root
Feb 10 06:57:34 odroid hass[13329]:     manifest_path = pathlib.Path(base) / domain / "manifest.json"
Feb 10 06:57:34 odroid hass[13329]: TypeError: unsupported operand type(s) for /: 'PosixPath' and 'NoneType'

And after about 20-30 seconds:

$ sudo systemctl status [email protected]
? [email protected] - Home Assistant
   Loaded: loaded (/etc/systemd/system/[email protected]; enabled; vendor preset: enabled)
   Active: deactivating (stop-sigterm) since Mon 2020-02-10 06:58:02 EST; 51s ago
 Main PID: 13329 (hass)
   CGroup: /system.slice/system-home\x2dassistant.slice/[email protected]
           +-13329 /srv/homeassistant/bin/python3 /srv/homeassistant/bin/hass -c /home/homeassistant/.homeassistant

Feb 10 06:57:34 odroid hass[13329]:     integration = await hass.async_add_executor_job(
Feb 10 06:57:34 odroid hass[13329]:   File "/usr/lib/python3.8/concurrent/futures/thread.py", line 57, in run
Feb 10 06:57:34 odroid hass[13329]:     result = self.fn(*self.args, **self.kwargs)
Feb 10 06:57:34 odroid hass[13329]:   File "/srv/homeassistant/lib/python3.8/site-packages/homeassistant/loader.py", line 154, in resolve_from_root
Feb 10 06:57:34 odroid hass[13329]:     manifest_path = pathlib.Path(base) / domain / "manifest.json"
Feb 10 06:57:34 odroid hass[13329]: TypeError: unsupported operand type(s) for /: 'PosixPath' and 'NoneType'
Feb 10 06:58:02 odroid systemd[1]: Stopping Home Assistant...
Feb 10 06:58:04 odroid hass[13329]: /srv/homeassistant/lib/python3.8/site-packages/asyncssh/crypto/ec.py:143: CryptographyDeprecationWarning: Support for unsafe construction of public numbers from encoded data will be removed in a future
Feb 10 06:58:04 odroid hass[13329]:   pub = ec.EllipticCurvePublicNumbers.from_encoded_point(curve(),
Feb 10 06:58:04 odroid hass[13329]: 2020-02-10 06:58:04 ERROR (MainThread) [alexapy.alexawebsocket] WebSocket Error: <class 'aiohttp.streams.EofStream'>

And the journalctl output:

-- Logs begin at Mon 2020-01-20 03:05:46 EST, end at Mon 2020-02-10 07:07:01 EST. --
Feb 10 06:57:25 odroid systemd[1]: Started Home Assistant.
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (SyncWorker_0) [homeassistant.loader] Loaded breaking_changes from custom_components.breaking_changes
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (SyncWorker_1) [homeassistant.loader] Loaded feedparser from custom_components.feedparser
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (SyncWorker_3) [homeassistant.loader] Loaded nwsradar from custom_components.nwsradar
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (SyncWorker_2) [homeassistant.loader] Loaded alexa_media from custom_components.alexa_media
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (SyncWorker_0) [homeassistant.loader] Loaded uilogs from custom_components.uilogs
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (SyncWorker_4) [homeassistant.loader] Loaded authenticated from custom_components.authenticated
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (SyncWorker_5) [homeassistant.loader] Loaded var from custom_components.var
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (SyncWorker_3) [homeassistant.loader] Loaded logbook_cache from custom_components.logbook_cache.bak
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (SyncWorker_2) [homeassistant.loader] Loaded hacs from custom_components.hacs
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (SyncWorker_0) [homeassistant.loader] Loaded system_health from homeassistant.components.system_health
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (SyncWorker_6) [homeassistant.loader] Loaded lovelace from homeassistant.components.lovelace
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (SyncWorker_7) [homeassistant.loader] Loaded logbook from homeassistant.components.logbook
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (SyncWorker_5) [homeassistant.loader] Loaded history from homeassistant.components.history
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 WARNING (MainThread) [homeassistant.loader] You are using a custom integration for alexa_media which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you do experience issues with Home Assistant.
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (SyncWorker_8) [homeassistant.loader] Loaded python_script from homeassistant.components.python_script
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (SyncWorker_0) [homeassistant.loader] Loaded automation from homeassistant.components.automation
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (SyncWorker_2) [homeassistant.loader] Loaded api from homeassistant.components.api
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (SyncWorker_4) [homeassistant.loader] Loaded logger from homeassistant.components.logger
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (SyncWorker_3) [homeassistant.loader] Loaded speedtestdotnet from homeassistant.components.speedtestdotnet
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (SyncWorker_1) [homeassistant.loader] Loaded updater from homeassistant.components.updater
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 WARNING (MainThread) [homeassistant.loader] You are using a custom integration for breaking_changes which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you do experience issues with Home Assistant.
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (SyncWorker_10) [homeassistant.loader] Loaded zwave from homeassistant.components.zwave
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (SyncWorker_5) [homeassistant.loader] Loaded zone from homeassistant.components.zone
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (SyncWorker_9) [homeassistant.loader] Loaded duckdns from homeassistant.components.duckdns
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 WARNING (MainThread) [homeassistant.loader] You are using a custom integration for hacs which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you do experience issues with Home Assistant.
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (SyncWorker_6) [homeassistant.loader] Loaded script from homeassistant.components.script
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (SyncWorker_11) [homeassistant.loader] Loaded asuswrt from homeassistant.components.asuswrt
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (SyncWorker_7) [homeassistant.loader] Loaded sun from homeassistant.components.sun
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (SyncWorker_10) [homeassistant.loader] Loaded config from homeassistant.components.config
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 WARNING (MainThread) [homeassistant.loader] You are using a custom integration for var which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you do experience issues with Home Assistant.
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (SyncWorker_8) [homeassistant.loader] Loaded notify from homeassistant.components.notify
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (SyncWorker_9) [homeassistant.loader] Loaded geo_location from homeassistant.components.geo_location
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (SyncWorker_2) [homeassistant.loader] Loaded input_boolean from homeassistant.components.input_boolean
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (SyncWorker_0) [homeassistant.loader] Loaded recorder from homeassistant.components.recorder
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (SyncWorker_5) [homeassistant.loader] Loaded scene from homeassistant.components.scene
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (SyncWorker_4) [homeassistant.loader] Loaded media_player from homeassistant.components.media_player
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (SyncWorker_3) [homeassistant.loader] Loaded input_datetime from homeassistant.components.input_datetime
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (SyncWorker_1) [homeassistant.loader] Loaded group from homeassistant.components.group
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (SyncWorker_6) [homeassistant.loader] Loaded life360 from homeassistant.components.life360
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (SyncWorker_7) [homeassistant.loader] Loaded websocket_api from homeassistant.components.websocket_api
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (SyncWorker_11) [homeassistant.loader] Loaded http from homeassistant.components.http
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (SyncWorker_10) [homeassistant.loader] Loaded binary_sensor from homeassistant.components.binary_sensor
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (SyncWorker_9) [homeassistant.loader] Loaded input_number from homeassistant.components.input_number
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (SyncWorker_8) [homeassistant.loader] Loaded vera from homeassistant.components.vera
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (SyncWorker_2) [homeassistant.loader] Loaded switch from homeassistant.components.switch
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (SyncWorker_0) [homeassistant.loader] Loaded ifttt from homeassistant.components.ifttt
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (SyncWorker_5) [homeassistant.loader] Loaded wwlln from homeassistant.components.wwlln
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (SyncWorker_4) [homeassistant.loader] Loaded upnp from homeassistant.components.upnp
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (SyncWorker_3) [homeassistant.loader] Loaded panel_iframe from homeassistant.components.panel_iframe
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (SyncWorker_1) [homeassistant.loader] Loaded device_tracker from homeassistant.components.device_tracker
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (SyncWorker_7) [homeassistant.loader] Loaded alexa from homeassistant.components.alexa
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (SyncWorker_6) [homeassistant.loader] Loaded discovery from homeassistant.components.discovery
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (SyncWorker_11) [homeassistant.loader] Loaded frontend from homeassistant.components.frontend
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (SyncWorker_10) [homeassistant.loader] Loaded rest_command from homeassistant.components.rest_command
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (SyncWorker_8) [homeassistant.loader] Loaded proximity from homeassistant.components.proximity
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (SyncWorker_9) [homeassistant.loader] Loaded sensor from homeassistant.components.sensor
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (SyncWorker_2) [homeassistant.loader] Loaded homeassistant from homeassistant.components.homeassistant
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (SyncWorker_5) [homeassistant.loader] Loaded persistent_notification from homeassistant.components.persistent_notification
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 WARNING (MainThread) [homeassistant.loader] You are using a custom integration for customizer which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you do experience issues with Home Assistant.
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (MainThread) [homeassistant.loader] Loaded customizer from custom_components.customizer
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (SyncWorker_0) [homeassistant.loader] Loaded device_automation from homeassistant.components.device_automation
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (SyncWorker_3) [homeassistant.loader] Loaded webhook from homeassistant.components.webhook
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (SyncWorker_1) [homeassistant.loader] Loaded auth from homeassistant.components.auth
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (MainThread) [homeassistant.setup] Setting up homeassistant
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (MainThread) [homeassistant.setup] Setup of domain homeassistant took 0.0 seconds.
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (MainThread) [homeassistant.setup] Setting up persistent_notification
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (MainThread) [homeassistant.setup] Setup of domain persistent_notification took 0.0 seconds.
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (SyncWorker_6) [homeassistant.loader] Loaded onboarding from homeassistant.components.onboarding
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (SyncWorker_10) [homeassistant.loader] Loaded person from homeassistant.components.person
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (SyncWorker_9) [homeassistant.loader] Loaded system_log from homeassistant.components.system_log
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (MainThread) [homeassistant.bootstrap] Setting up {'logger', 'system_log'}
Feb 10 06:57:28 odroid hass[13329]: 2020-02-10 06:57:28 INFO (MainThread) [homeassistant.setup] Setting up logger
Feb 10 06:57:34 odroid hass[13329]: 2020-02-10 06:57:34 ERROR (MainThread) [homeassistant.core] Error doing job: Task exception was never retrieved
Feb 10 06:57:34 odroid hass[13329]: Traceback (most recent call last):
Feb 10 06:57:34 odroid hass[13329]:   File "/srv/homeassistant/lib/python3.8/site-packages/homeassistant/helpers/entity_component.py", line 213, in async_setup_platform
Feb 10 06:57:34 odroid hass[13329]:     platform = await async_prepare_setup_platform(
Feb 10 06:57:34 odroid hass[13329]:   File "/srv/homeassistant/lib/python3.8/site-packages/homeassistant/setup.py", line 229, in async_prepare_setup_platform
Feb 10 06:57:34 odroid hass[13329]:     integration = await loader.async_get_integration(hass, platform_name)
Feb 10 06:57:34 odroid hass[13329]:   File "/srv/homeassistant/lib/python3.8/site-packages/homeassistant/loader.py", line 310, in async_get_integration
Feb 10 06:57:34 odroid hass[13329]:     integration = await hass.async_add_executor_job(
Feb 10 06:57:34 odroid hass[13329]:   File "/usr/lib/python3.8/concurrent/futures/thread.py", line 57, in run
Feb 10 06:57:34 odroid hass[13329]:     result = self.fn(*self.args, **self.kwargs)
Feb 10 06:57:34 odroid hass[13329]:   File "/srv/homeassistant/lib/python3.8/site-packages/homeassistant/loader.py", line 154, in resolve_from_root
Feb 10 06:57:34 odroid hass[13329]:     manifest_path = pathlib.Path(base) / domain / "manifest.json"
Feb 10 06:57:34 odroid hass[13329]: TypeError: unsupported operand type(s) for /: 'PosixPath' and 'NoneType'
Feb 10 06:58:02 odroid systemd[1]: Stopping Home Assistant...
Feb 10 06:58:04 odroid hass[13329]: /srv/homeassistant/lib/python3.8/site-packages/asyncssh/crypto/ec.py:143: CryptographyDeprecationWarning: Support for unsafe construction of public numbers from encoded data will be removed in a future version. Please use EllipticCurvePublicKey.from_encoded_point
Feb 10 06:58:04 odroid hass[13329]:   pub = ec.EllipticCurvePublicNumbers.from_encoded_point(curve(),
Feb 10 06:58:04 odroid hass[13329]: 2020-02-10 06:58:04 ERROR (MainThread) [alexapy.alexawebsocket] WebSocket Error: <class 'aiohttp.streams.EofStream'>
Feb 10 06:59:32 odroid systemd[1]: [email protected]: State 'stop-sigterm' timed out. Killing.
Feb 10 06:59:32 odroid systemd[1]: [email protected]: Killing process 13329 (hass) with signal SIGKILL.
Feb 10 06:59:32 odroid systemd[1]: [email protected]: Main process exited, code=killed, status=9/KILL
Feb 10 06:59:32 odroid systemd[1]: [email protected]: Failed with result 'timeout'.
Feb 10 06:59:32 odroid systemd[1]: Stopped Home Assistant.

Even disabling the components that are throwing errors (alexa_media & asuswrt) it still dies via systemd, but if I run it from the command line even with them enabled it works.

Not sure if it will help, but here’s what I have:

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

[Service]
Type=simple
User=%i
ExecStart=/srv/homeassistant/bin/hass -c "/home/homeassistant/.homeassistant"

[Install]
WantedBy=multi-user.target

I see yours doesn’t have a dependency on the database server like mine has (e.g., see mariadb.service listed in After.) Although I’m not familiar enough with these details to know if that could explain “State 'stop-sigterm' timed out. Killing.”.

This happens when SystemD is unable to gracefully stop a service.

1 Like

I had the mariadb.service in there previously as I was using it, but not right at the moment. Trying something radical that’s showing some promise. I need to play some more before posting about it though.

Unfortunately I don’t have time to dig deeper right now, but it’s something in the .storage that’s killing it. I set my config back to what had been working and works when I run hass directly from the command line. I then moved my .storage to .storage.bak and recreated a blank .storage. The system then started and it prompted me as a new user without any sort of setup. I stopped the system and copied my auth* files from the back up over to the new .storage and restarted. Again started and it’s staying runnning, but I’m getting a “site can’t be reached” in the browser. I’ve reset things to run from the command line to get me through the night again and will pick it up again tomorrow when I have more time to work on it. Progress. :slight_smile:

All is well again. I found the problem…PEBKAC! I was reviewing logs while mucking about with the .storage files, when i realized I kept seeing my MariaDB watchdog process which runs every minute when using MariaDB this is fine, but when I’m not, it’s a major problem. This script will shutdown HA via systemctl if the DB isn’t accessible. Thus when running HA directly from the command line it does nothing because it wasn’t started via systemd. But when started with systemd WITHOUT MariaDB running, the watchdog sees that and shuts down HA just like it should! I thought I had disabled it, but apparently I had not, or I re-enabled it. “We have met the enemy and he is us.” This is what I get for trying to do too many things at once. Thank you to @pnbruckner, @user535733 and @firstof9 for at least entertaining my folly. :smiley:

2 Likes