Startup problems on v1.9.4 about smarthome HOT 23 CLOSED

2023-03-14 13:51:28 CRITICAL plugins.database Database: Initialization failed: unable to open database file
2023-03-14 13:51:28 NOTICE lib.smarthome -------------------- SmartHomeNG restarting, initiated by SmartHomeNG (Database plugin stalled) --------------------

What were the next entries in the log? The stalled database Plugin should trigger a restart and after the restart the database plugin should come up properly. Seldom, it can take two restarts for the database plugin to resolve the problem that occured (in your case probably through the aborts caused by the errors above)

Btw.: your etc/logging.yaml must be quite old. Otherwise you would not get the log entry

2023-03-14 13:51:26 NOTICE lib.smarthome - Loglevel NOTICE is set to value 31 because handler of root logger is set to level WARNING or higher - Set level of handler 'shng_warnings_file' to 'NOTICE'!

Your can resolve this by following the advice from the log entry ans set the level of the handler shng_warnings_file to NOTICE

I am looking into

File "/usr/local/smarthome/lib/shpypi.py", line 1400, in _consolidate_requirements
print('p=' + p)

Interesting, that no one stumbled over that in the development phase.

from smarthome.

What was the content of the line printed before the error

File "/usr/local/smarthome/lib/shpypi.py", line 1400, in _consolidate_requirements
print('p=' + p)
TypeError: can only concatenate str (not "dict") to str

from smarthome.

What were the next entries in the log? The stalled database Plugin should trigger a restart and after the restart the database plugin should come up properly.

Its starting over and over again:

2023-03-14 13:51:28 NOTICE lib.smarthome -------------------- SmartHomeNG restarting, initiated by SmartHomeNG (Database plugin stalled) --------------------
2023-03-14 13:51:39 NOTICE lib.smarthome -------------------- SmartHomeNG stopped --------------------
2023-03-14 13:51:39 ERROR asyncio Task was destroyed but it is pending!
task: <Task pending name='ws_server' coro=<Websocket.ws_server() running at /usr/local/smarthome/modules/websocket/init.py:265> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7fe040121040>()]>>
2023-03-14 13:51:39 ERROR asyncio Task was destroyed but it is pending!
task: <Task pending name='wss_server' coro=<Websocket.ws_server() running at /usr/local/smarthome/modules/websocket/init.py:265> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7fe040121100>()]>>
2023-03-14 13:51:39 ERROR asyncio Task was destroyed but it is pending!
task: <Task pending name='update_visu' coro=<Protocol.update_visu() running at /usr/local/smarthome/modules/websocket/smartvisu.py:751> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7fe0401210d0>()]>>
2023-03-14 13:51:39 ERROR asyncio Task was destroyed but it is pending!
task: <Task pending name='update_all_series' coro=<Protocol.update_all_series() running at /usr/local/smarthome/modules/websocket/smartvisu.py:549> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7fe040121160>()]>>
2023-03-14 13:51:40 NOTICE lib.smarthome -------------------- Init SmartHomeNG v1.9.4-master (c0cfb39) --------------------
2023-03-14 13:51:40 NOTICE lib.smarthome Running in Python interpreter 'v3.8.10 final', from directory /usr/local/smarthome
2023-03-14 13:51:40 NOTICE lib.smarthome - operating system 'Ubuntu 20.04.5 LTS' (pid=8598)
2023-03-14 13:51:41 NOTICE lib.smarthome - on 'Intel Xeon E3-12xx v2 (Ivy Bridge, IBRS)'
2023-03-14 13:51:41 NOTICE lib.smarthome - Loglevel NOTICE is set to value 31 because handler of root logger is set to level WARNING or higher - Set level of handler 'shng_warnings_file' to 'NOTICE'!
2023-03-14 13:51:42 NOTICE lib.smarthome - Nutze Feiertage für Land 'IT', Provinz 'BZ', 1 benutzerdefinierte(r) Feiertag(e) definiert
2023-03-14 13:51:43 WARNING lib.module Not loading module Mqtt from section 'mqtt': Module is disabled
2023-03-14 13:51:43 NOTICE lib.userfunctions Imported userfunctions from 'server' v1.0.0 - Server functions
2023-03-14 13:51:43 NOTICE lib.userfunctions Imported userfunctions from 'utils' v1.0.0 - Diverse Funktionen
2023-03-14 13:51:43 ERROR lib.db Database [Database]: Could not connect to the database using 'sqlite3': unable to open database file
2023-03-14 13:51:43 CRITICAL plugins.database Database: Initialization failed: unable to open database file
2023-03-14 13:51:43 NOTICE lib.smarthome -------------------- SmartHomeNG restarting, initiated by SmartHomeNG (Database plugin stalled) --------------------
2023-03-14 13:51:54 NOTICE lib.smarthome -------------------- SmartHomeNG stopped --------------------
2023-03-14 13:51:54 ERROR asyncio Task was destroyed but it is pending!
task: <Task pending name='ws_server' coro=<Websocket.ws_server() running at /usr/local/smarthome/modules/websocket/init.py:265> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7f347c0ee6a0>()]>>
2023-03-14 13:51:54 ERROR asyncio Task was destroyed but it is pending!
task: <Task pending name='wss_server' coro=<Websocket.ws_server() running at /usr/local/smarthome/modules/websocket/init.py:265> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7f347c0ee580>()]>>
2023-03-14 13:51:54 ERROR asyncio Task was destroyed but it is pending!
task: <Task pending name='update_visu' coro=<Protocol.update_visu() running at /usr/local/smarthome/modules/websocket/smartvisu.py:751> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7f347c0ee910>()]>>
2023-03-14 13:51:54 ERROR asyncio Task was destroyed but it is pending!
task: <Task pending name='update_all_series' coro=<Protocol.update_all_series() running at /usr/local/smarthome/modules/websocket/smartvisu.py:549> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7f347c0ee730>()]>>
2023-03-14 13:51:55 NOTICE lib.smarthome -------------------- Init SmartHomeNG v1.9.4-master (c0cfb39) --------------------
2023-03-14 13:51:55 NOTICE lib.smarthome Running in Python interpreter 'v3.8.10 final', from directory /usr/local/smarthome
2023-03-14 13:51:55 NOTICE lib.smarthome - operating system 'Ubuntu 20.04.5 LTS' (pid=8672)
2023-03-14 13:51:57 NOTICE lib.smarthome - on 'Intel Xeon E3-12xx v2 (Ivy Bridge, IBRS)'
2023-03-14 13:51:57 NOTICE lib.smarthome - Loglevel NOTICE is set to value 31 because handler of root logger is set to level WARNING or higher - Set level of handler 'shng_warnings_file' to 'NOTICE'!
2023-03-14 13:51:58 NOTICE lib.smarthome - Nutze Feiertage für Land 'IT', Provinz 'BZ', 1 benutzerdefinierte(r) Feiertag(e) definiert
2023-03-14 13:51:58 WARNING lib.module Not loading module Mqtt from section 'mqtt': Module is disabled
2023-03-14 13:51:59 NOTICE lib.userfunctions Imported userfunctions from 'server' v1.0.0 - Server functions
2023-03-14 13:51:59 NOTICE lib.userfunctions Imported userfunctions from 'utils' v1.0.0 - Diverse Funktionen
2023-03-14 13:51:59 ERROR lib.db Database [Database]: Could not connect to the database using 'sqlite3': unable to open database file
2023-03-14 13:51:59 CRITICAL plugins.database Database: Initialization failed: unable to open database file
2023-03-14 13:51:59 NOTICE lib.smarthome -------------------- SmartHomeNG restarting, initiated by SmartHomeNG (Database plugin stalled) --------------------

Your can resolve this by following the advice from the log entry ans set the level of the handler shng_warnings_file to NOTICE

Thank you. Did it

from smarthome.

What was the content of the line printed before the error

####@####:/usr/local/smarthome$ python3 bin/smarthome.py
p Gleichheit p['key']=py-vapid+: >< / >1.8.2<
Traceback (most recent call last):
File "bin/smarthome.py", line 118, in
core_reqs = shpypi.test_core_requirements(logging=False, pip3_command=args.pip3_command)
File "/usr/local/smarthome/lib/shpypi.py", line 238, in test_core_requirements
self.req_files.create_requirementsfile('all')
File "/usr/local/smarthome/lib/shpypi.py", line 1485, in create_requirementsfile
packagelist_consolidated = self._consolidate_requirements(packagelist)
File "/usr/local/smarthome/lib/shpypi.py", line 1394, in _consolidate_requirements
print('p=' + p)
TypeError: can only concatenate str (not "dict") to str

from smarthome.

To the error:

2023-03-14 13:40:46 ERROR lib.shpypi ERROR: Could not open requirements file: [Errno 2] No such file or directory: 'requirements/conf_all.txt'

• What are the contents of the requirements directory?
• Has the user that starts smarthome.py write access to that directory?
• Have you set the access rights for the smarthome user to the smarthome directory (and subdirectories) according to the documentation?
• Is the service starting smarthome.py with the smarthome user?

Problems with access rights are likely, if you have started SmartHomeNG with and user with administrative rights (like root)

from smarthome.

My user is administrator, wich also starts the service and has all the rights in /usr/local/smarthome. Beside the name itself its the same user as the smarthome user from the doc.

Shortened content of the /etc/systemd/system/smarthome.service file:

[Service]
Type=forking
ExecStart=/usr/bin/python3 /usr/local/smarthome/bin/smarthome.py
WorkingDirectory=/usr/local/smarthome
User=administrator

ls -l requirements/

total 20
-rwxrwxrwx 1 administrator administrator 4850 Mär 14 14:49 all.txt
-rwxrwxrwx 1 administrator administrator 1364 Mär 14 14:49 base.txt
-rwxrwxrwx 1 administrator administrator 2446 Mär 14 14:49 conf_all.txt
-rwxrwxrwx 1 administrator administrator 1824 Okt 31 20:17 test.txt

ls -l smarthome/

total 132
drwxrwxr-x 3 administrator administrator 4096 Mär 14 14:33 bin
-rw-rw-r-- 1 administrator administrator 90 Feb 8 2022 CHANGELOG.md
drwxrwxr-x 3 administrator administrator 4096 Feb 8 2022 deprecated
drwxrwxr-x 5 administrator administrator 4096 Okt 31 20:17 dev
drwxrwxr-x 4 administrator administrator 4096 Okt 31 20:17 doc
drwxrwxr-x 2 administrator administrator 4096 Mär 14 14:33 etc
drwxrwxr-x 3 administrator administrator 4096 Nov 2 09:37 functions
drwxrwxr-x 2 administrator administrator 4096 Mär 14 11:15 items
drwxrwxr-x 6 administrator administrator 4096 Mär 14 14:35 lib
-rw-rw-r-- 1 administrator administrator 35147 Feb 8 2022 LICENSE
drwxrwxr-x 2 administrator administrator 4096 Feb 8 2022 log
drwxrwxr-x 2 administrator administrator 4096 Mär 14 13:11 logics
drwxrwxr-x 2 administrator administrator 4096 Feb 8 2022 media
drwxrwxr-x 8 administrator administrator 4096 Feb 8 2022 modules
drwxrwxr-x 167 administrator administrator 4096 Mär 14 13:12 plugins
-rw-rw-r-- 1 administrator administrator 7329 Mär 14 14:33 README.md
drwxrwxrwx 2 administrator administrator 4096 Mär 14 14:54 requirements
drwxrwxr-x 2 administrator administrator 4096 Feb 9 2022 scenes
-rw-rw-r-- 1 administrator administrator 1301 Feb 8 2022 setup.py
drwxrwxr-x 4 administrator administrator 4096 Okt 31 20:17 tests
drwxrwxr-x 2 administrator administrator 4096 Mär 14 14:33 tools
-rw-rw-r-- 1 administrator administrator 4209 Okt 31 20:17 tox.ini
drwxrwxr-x 10 administrator administrator 4096 Mär 14 13:42 var

I have no problems at all on v1.9.3

from smarthome.

The error was

2023-03-14 13:40:46 ERROR lib.shpypi ERROR: Could not open requirements file: [Errno 2] No such file or directory: 'requirements/conf_all.txt'

your listing shows, that the file has been created, so the error should have disappeared, right?

from smarthome.

I have no idea, why lib.db could not open your sqlite3 database.
Can you open the database using administration tools without error?

from smarthome.

Btw. your configuration of the service is quite old. There are some parameters missing. That would not explain the error(s), but would explain some loops you are experiencing.

Missing as e.g. the parameters PIDFile, Restart, RestartForceExitStatus.

Take a look at the documentation (english translation): https://smarthomeng-github-io.translate.goog/smarthome/installation/komplettanleitung/08_shng_daemon.html?_x_tr_sl=de&_x_tr_tl=en&_x_tr_hl=de

from smarthome.

your listing shows, that the file has been created, so the error should have disappeared, right?

The creation of the file works everytime when I restart the service (according to the time in the file header). But the error is still there.

from smarthome.

Btw. your configuration of the service is quite old.

No the config is actual, I copied again a few minutes ago to be sure there is no typo in there. The content in the reply above is the shortened version.

from smarthome.

I have no idea, why lib.db could not open your sqlite3 database. Can you open the database using administration tools without error?

I have to try it, but since the same database file has no problems when I go back to v1.9.3, I do not think its the database itself.

from smarthome.

Interesting. At the moment, I see no reason for a different behavior between 1.9.3 and 1.9.4 for the database.

from smarthome.

your listing shows, that the file has been created, so the error should have disappeared, right?

The creation of the file works everytime when I restart the service (according to the time in the file header). But the error is still there.

If the file is being created, there is no reason for the error (from the info you posted). If the file is there, and SmartHomeNG can't oben it, there has to be a access-rights conflict.

2023-03-14 13:40:46 ERROR lib.shpypi ERROR: Could not open requirements file: [Errno 2] No such file or directory: 'requirements/conf_all.txt'

from smarthome.

I will continue my research and give you feedback.

Thanks for your support.

from smarthome.

2023-03-14 13:40:46 ERROR lib.shpypi ERROR: Could not open requirements file: [Errno 2] No such file or directory: 'requirements/conf_all.txt'

Possibly this is not a access rights problem, but a relative-path-one. Can you assert that the service is started from the correct working dir?

Is the shng-directory maybe accessed via a softlink?

from smarthome.

your listing shows, that the file has been created, so the error should have disappeared, right?

The creation of the file works everytime when I restart the service (according to the time in the file header). But the error is still there.

I took another look at your logs. I can find the error only in the first log you posted (at 13:40:46), but not in the later logs. Am I hunting a ghost?

from smarthome.

I have an idea in regards to the database problem:

Maybe another instance of SmartHomeNG is running.
What is the output of bash tools/test_running?

from smarthome.

How is your database plugin configured?

from smarthome.

According to the requirements problem:

No your not hunting a ghost ;) . As I mentioned in my first post, I installed the missing pip module by hand to move on and keep testing. But when I uninstall a requirement the error is still there. But I think its better to fix first the database problem.

According to the database problem:

Interresting, on v1.9.3 bash tools/test_running gives me only one instance of shng but v1.9.4 gives me always these three:

adminis+ 1446 1 50 07:45 ? 00:00:02 /usr/bin/python3 /usr/local/smarthome/bin/smarthome.py
adminis+ 1480 1446 0 07:45 ? 00:00:00 /bin/sh -c /usr/bin/python3 /usr/local/smarthome/bin/smarthome.py -r
adminis+ 1481 1480 56 07:45 ? 00:00:00 /usr/bin/python3 /usr/local/smarthome/bin/smarthome.py -r

and it does not matter if i start it via the service or manually. So your

Maybe another instance of SmartHomeNG is running.

could be the case.

My database plugin configuration is:

database:
plugin_name: database
driver: sqlite3
connect:
- database:./var/db/smarthomeng.db
- check_same_thread:0

Btw. the Problem ist there with both of the versions v1.9.3 and v1.9.4 of shng/plugins on shng v1.9.4.

from smarthome.

For the database problem:
Use the absolute path to the database file. That should work.

For the problem with the installation of requirements:
At the moment (with v1.9.4) you have to install the requirements manually using the conf_all.txt file.

I found out yesterday, that there is a constellation in lib.shpypi under which the requirements file cannot be installed. The pip command is invoked with the relative path requirements/conf_all.txt. In the case of a problem, however, the cwd is not the SmartHomeNG base directory.

In the develop branch is a new version, which uses the absolute path.

from smarthome.

Use the absolute path to the database file. That should work.

You are totally right!! It fixed the problem. Its verry interesting because I deploy another shng installation and since it worked now here i did the update also there without any problems (the path to the db is there still relative).

In the develop branch is a new version, which uses the absolute path.

I switched to the develop branch and the problem with the requirements was gone, the installation adds the needed modules by itself and restarts as intended.

Thanks a lot for your help and time. You can close the issue.
Greets

from smarthome.

For the database issue: I use a refative pathname too, but something in your Installation causes the cwd to be changed and then the database file could not be found…

Someone else had the same problem and it was fixed by using the absolute path too.

from smarthome.