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

[BUG]: failure after adding a sensor triggered area #647

Closed
kahuwi14 opened this issue Jan 15, 2022 · 15 comments
Closed

[BUG]: failure after adding a sensor triggered area #647

kahuwi14 opened this issue Jan 15, 2022 · 15 comments

Comments

@kahuwi14
Copy link
Contributor

kahuwi14 commented Jan 15, 2022 •
edited

Setup:

  • TerrariumPI version: 4 (on docker)
  • Raspberry PI: 3B
  • Docker: 20.10.12
  • Linux: Raspbian buster (5.10.63-v7+)

Describe the bug
First of all, I added the lights and that worked as expected.
After adding an area for the humidity or for the heating (both ended up in the same failure with excatly the same lines of code),
I got the following issue.
After this failure, the frontend slowly dies and the container changes into "unhealthy"-state.
Only a roleback to the previous-config brings the system back to life.

Log:

2022-01-15 22:19:51,409 - INFO    - terrariumEngine       - Starting TerrariumPI 4.1.0 ...
2022-01-15 22:19:51,542 - INFO    - terrariumEngine       - Loaded 28 settings in 0.13 seconds.
2022-01-15 22:19:51,560 - INFO    - terrariumEngine       - Loading weather data from source https://api.openweathermap.org/data/2.5/weather?q=XXX,de&appid=XXX
2022-01-15 22:19:53,081 - INFO    - weather.openweathermap_org_weather - Loaded new historical weather data (48 measurements) from 2022-01-13 02:00:00 till 2022-01-15 01:00:00 in 0.75 seconds.
2022-01-15 22:19:53,086 - INFO    - weather               - Loaded new weather data in 1.520 seconds.
2022-01-15 22:19:55,316 - INFO    - terrariumEngine       - Loading existing sensors from database.
2022-01-15 22:19:55,887 - INFO    - terrariumEngine       - Loaded sensor dht22 temperature named 'Temperatur' at address '3' with value 17.50C in 0.56 seconds.
2022-01-15 22:19:55,893 - INFO    - terrariumEngine       - Loaded sensor dht22 humidity named 'Luftfeuchtigkeit' at address '3' with value 91.70% in 0.01 seconds.
2022-01-15 22:19:55,907 - INFO    - terrariumEngine       - Loaded sensor hc-sr04 distance named 'Wasserstand' at address '7,11' with value 8.42cm in 0.01 seconds.
2022-01-15 22:19:56,820 - INFO    - terrariumEngine       - Loaded sensor 1wire temperature named 'Hostspot' at address '28-0517a21d84ff' with value 16.50C in 0.91 seconds.
2022-01-15 22:19:56,823 - INFO    - terrariumEngine       - Scanning for new sensors ...
2022-01-15 22:20:06,928 - INFO    - terrariumEngine       - Loaded 4 sensors in 11.61 seconds.
2022-01-15 22:20:06,930 - INFO    - terrariumEngine       - Loading existing relays from database.
2022-01-15 22:20:08,142 - INFO    - terrariumEngine       - Loaded relay gpio-inverse relay named 'Taglicht' at address '5' value 0.00 in 1.14 seconds.
2022-01-15 22:20:08,155 - INFO    - terrariumEngine       - Loaded relay gpio-inverse relay named 'Heizmatte' at address '36' value 0.00 in 0.01 seconds.
2022-01-15 22:20:08,168 - INFO    - terrariumEngine       - Loaded relay gpio-inverse relay named 'Beregnung' at address '8' value 0.00 in 0.01 seconds.
2022-01-15 22:20:08,242 - INFO    - terrariumEngine       - Loaded relay gpio-inverse relay named 'Nachtlicht' at address '32' value 100.00 in 0.07 seconds.
2022-01-15 22:20:08,245 - INFO    - terrariumEngine       - Scanning for new relays ...
No GEMBIRD SiS-PM found. Check USB connections, please!
2022-01-15 22:20:18,616 - INFO    - terrariumEngine       - Loaded 4 relays in 11.69 seconds.
2022-01-15 22:20:18,619 - INFO    - terrariumEngine       - Loading existing buttons from database.
2022-01-15 22:20:18,713 - INFO    - terrariumEngine       - Loaded magnetic button 'Frontscheibe' at address '31' value 1.00 in 0.08 seconds.
2022-01-15 22:20:18,715 - INFO    - terrariumEngine       - Loaded 1 buttons in 0.10 seconds.
2022-01-15 22:20:18,716 - INFO    - terrariumEngine       - Loading existing webcams from database.
2022-01-15 22:20:18,723 - INFO    - terrariumEngine       - Loaded 0 webcams in 0.01 seconds.
2022-01-15 22:20:18,725 - INFO    - terrariumEngine       - Loading existing enclosures from database.
2022-01-15 22:20:18,739 - INFO    - terrariumEngine       - Loaded Enclosure Ernie with 1 areas in 0.01 seconds.
2022-01-15 22:20:18,741 - INFO    - terrariumEngine       - Loaded 1 enclosures in 0.02 seconds.
2022-01-15 22:20:18,920 - INFO    - terrariumEngine       - TerrariumPI is up and running at address: http://terrariumpi.kahuwi:8090 in 28.93 seconds.
2022-01-15 22:20:19,000 - INFO    - terrariumWebserver    - Running webserver at terrariumpi.kahuwi:8090
/opt/venv/lib/python3.8/site-packages/bottle.py:3345: DeprecationWarning: Absolute template path names are deprecated.
  fname = self.search(name, self.lookup)
2022-01-15 22:23:23,885 - WARNING - hardware.sensor       - Invalid reading from sensor DHT22 sensor temperature named 'Temperatur' at address '3', retrying in 0.5 seconds...
2022-01-15 22:26:24,892 - WARNING - hardware.sensor       - Invalid reading from sensor DHT22 sensor temperature named 'Temperatur' at address '3', retrying in 0.5 seconds...
Exception in thread Thread-28:
Traceback (most recent call last):
  File "/usr/local/lib/python3.8/threading.py", line 932, in _bootstrap_inner
    self.run()
  File "/usr/local/lib/python3.8/threading.py", line 870, in run
    self._target(*self._args, **self._kwargs)
  File "/TerrariumPI/terrariumEngine.py", line 1049, in __engine_loop
    self._update_enclosures()
  File "/TerrariumPI/terrariumEngine.py", line 971, in _update_enclosures
    area_states = self.enclosures[str(enclosure.id)].update(read_only)
  File "/TerrariumPI/terrariumEnclosure.py", line 128, in update
    area_states[area_id] = self.areas[area_id].update(read_only)
  File "/TerrariumPI/terrariumArea.py", line 883, in update
    super().update(read_only)
  File "/TerrariumPI/terrariumArea.py", line 565, in update
    depends_on_alarm = depends_on_alarm or self.enclosure.areas[area].state['sensors']['alarm']
KeyError: 'sensors'

After killing and restarting the container some additional lines appear in the log:

Traceback (most recent call last):
  File "/usr/local/lib/python3.8/threading.py", line 932, in _bootstrap_inner 
    self.run()
  File "/opt/venv/lib/python3.8/site-packages/pigpio.py", line 1196, in run
    buf += self.sl.s.recv(RECV_SIZ)

config-screenshot:
image

If you need something else, just let me know.
@kahuwi14 kahuwi14 changed the title [BUG]: [BUG]: failure after adding a sensor triggered area Jan 15, 2022
@kahuwi14
Copy link
Contributor Author

I just experienced another crash after adding a weather-triggered second area:

Exception in thread Thread-28:
Traceback (most recent call last):
  File "/usr/local/lib/python3.8/threading.py", line 932, in _bootstrap_inner
    self.run()
  File "/usr/local/lib/python3.8/threading.py", line 870, in run
    self._target(*self._args, **self._kwargs)
  File "/TerrariumPI/terrariumEngine.py", line 1049, in __engine_loop
    self._update_enclosures()
  File "/TerrariumPI/terrariumEngine.py", line 971, in _update_enclosures
    area_states = self.enclosures[str(enclosure.id)].update(read_only)
  File "/TerrariumPI/terrariumEnclosure.py", line 121, in update
    area_states[area_id] = self.areas[area_id].update(read_only)
  File "/TerrariumPI/terrariumArea.py", line 654, in update
    self.relays_toggle(period,True)
  File "/TerrariumPI/terrariumArea.py", line 725, in relays_toggle
    self._relay_action(part, relay, on)
  File "/TerrariumPI/terrariumArea.py", line 842, in _relay_action
    action_ok = self.enclosure.relays[relay.id].on(relay.ON if action else relay.OFF, delay=delay)
  File "/TerrariumPI/hardware/relay/__init__.py", line 254, in on
    changed = self.set_state(value)
  File "/TerrariumPI/hardware/relay/__init__.py", line 230, in set_state
    self.callback(self.id, self.state)
  File "/TerrariumPI/terrariumEngine.py", line 770, in callback_relay
    self._update_enclosures(True)
  File "/TerrariumPI/terrariumEngine.py", line 971, in _update_enclosures
    area_states = self.enclosures[str(enclosure.id)].update(read_only)
  File "/TerrariumPI/terrariumEnclosure.py", line 121, in update
    area_states[area_id] = self.areas[area_id].update(read_only)
  File "/TerrariumPI/terrariumArea.py", line 670, in update
    self.state['powered'] = self._powered
  File "/TerrariumPI/terrariumArea.py", line 141, in _powered
    if period not in self.state or len(self.setup[period]['relays']) == 0:
KeyError: 'night'

I'll pull the container again and this will fix this mess

@kahuwi14
Copy link
Contributor Author

kahuwi14 commented Jan 16, 2022 •
edited

And some more information:

I just witnessed, that the "latest"-build is not the 4.1.0-build in docker!
image

PS: the date is the build-date

@theyosh
Copy link
Owner

theyosh commented Jan 16, 2022

Latest is a newer version... should work. I used that for testing but I will remove it. For now stick with the version 4.1.0

And in order to reset this, just remove the database files at location /opt/TerrariumPI/data. Then when it restarts, it starts clean.

@kahuwi14
Copy link
Contributor Author

I already did this, while testing with different configurations. The problems appear every time, I add a second area.
Any other change does not lead to the error...

I'll do more testing tomorrow..

@kahuwi14
Copy link
Contributor Author

kahuwi14 commented Jan 17, 2022 •
edited

And another Problem after adding a second mqtt-service.

Exception in thread Thread-5382:
Traceback (most recent call last):
  File "/usr/local/lib/python3.8/threading.py", line 932, in _bootstrap_inner
    self.run()
  File "/usr/local/lib/python3.8/threading.py", line 870, in run
    self._target(*self._args, **self._kwargs)
  File "/TerrariumPI/terrariumEngine.py", line 729, in _update_relays
    self.notification.message(f'relay_update' , relay_data)
  File "/TerrariumPI/terrariumNotification.py", line 328, in message
    if self.services[service.id] is None:
KeyError: 'a9af7309-e9e2-47b9-a548-0108c7df2bbf'

Additionally, mqtt doesn't work (I don't see any logins on the mqtt-Server) at all but throws no errors.

theyosh added a commit that referenced this issue Jan 17, 2022
@theyosh
More area checks. #647
f0bfab4
@theyosh
Copy link
Owner

theyosh commented Jan 17, 2022

I am currently making a new docker image (version test) that you could use. It think it will be ready in about 2 hours from now.

First issue is that you have selected a dependency on you lights area. That does not work. You should toggle the main lights switch in you Light area Tageslight, so that the enclosure knows that that area is the one for checking the light status which you have selected to Ein. So remove the area from the dependency.

Second one looks something not correct on the lights area. Not sure how many you have configured, but at least one is faulty. It could be fixed with the main lights switch again. Not sure....

And the notification part is not yet finished in the 4.1.0 version. In the test version is should almost be finished. But I have not tested with two MQTT accounts. But with one account, I think it should work. I have made a connection to an external server without an error and sending messages is also not giving an error. Therefore I guess it should work with at least one account.

@kahuwi14
Copy link
Contributor Author

kahuwi14 commented Jan 18, 2022 •
edited

First of all: thanks for the super fast response

Something went wrong with the encryption in matrix...
I can not read your yesterdays message..

This morning, I tried the config (that didn't work in docker) on fresh normal installation and it worked.
Now I pulled the test-docker and it worked also!

First issue is that you have selected a dependency on you lights area. That does not work. You should toggle the main lights switch in you Light area Tageslight, so that the enclosure knows that that area is the one for checking the light status which you have selected to Ein. So remove the area from the dependency.

Ahh ok! That makes sense. But then, I didn't understand this field.. ;)

Second one looks something not correct on the lights area. Not sure how many you have configured, but at least one is faulty. It could be fixed with the main lights switch again. Not sure....

I had only the one area for the lights and the switch was set, but it seems to be working for now.

And the notification part is not yet finished in the 4.1.0 version. In the test version is should almost be finished. But I have not tested with two MQTT accounts. But with one account, I think it should work. I have made a connection to an external server without an error and sending messages is also not giving an error. Therefore I guess it should work with at least one account.

I tested with correct and false crendetials, ports and hostname but there are no reactions in the logs at all.
What should be put into the notification-config-fields?

@kahuwi14
Copy link
Contributor Author

After some further investigation, It turned out, that the load_setup(self, setup_data) is only excecuted at the startup, not after a save-operation of the gui. Therefore, the mqtt-config is not tested, until the system is restarted.

After a restart, I've got this Error:

2022-01-18 13:50:44,766 - INFO    - terrariumEngine       - Loading existing sensors from database.
OSError: [Errno 0] Error
    self._sslobj.do_handshake()
  File "/home/pi/TerrariumPI/venv/lib/python3.7/site-packages/gevent/_ssl3.py", line 666, in do_handshake
    sock.do_handshake()
  File "/home/pi/TerrariumPI/venv/lib/python3.7/site-packages/paho/mqtt/client.py", line 1073, in reconnect
    return self.reconnect()
  File "/home/pi/TerrariumPI/venv/lib/python3.7/site-packages/paho/mqtt/client.py", line 914, in connect
    self.connection.connect(self.setup['address'], self.setup['port'], 30)
  File "/home/pi/TerrariumPI/terrariumNotification.py", line 1185, in load_setup
Traceback (most recent call last):
2022-01-18 13:50:43,734 - ERROR   - terrariumNotification - Failed connecting to MQTT Broker at address: iobroker.kahuwi:1884: [Errno 0] Error
2022-01-18 13:50:43,540 - INFO    - weather               - Loaded new weather data in 1.348 seconds.

I'm now trying to find, what's the problem here.

@theyosh
Copy link
Owner

theyosh commented Jan 27, 2022

Hi, did we fix this during a Matrix chat? Only thing left is (re)loading the service after changing/adding...

@kahuwi14
Copy link
Contributor Author

Hi!
oh yes, of course we did!
Sorry... ;)

theyosh added a commit that referenced this issue Jan 27, 2022
@theyosh
Fix message service reloading. #647
afce6f8
@theyosh
Copy link
Owner

theyosh commented Jan 27, 2022

So the reloading should now also be fixed. And when there are errors with the MQTT server, it will not hammer over and over but just stops with an error.

@theyosh
Copy link
Owner

theyosh commented Jan 27, 2022

So, if you can test this, and confirm, then we can close this issue

@kahuwi14
Copy link
Contributor Author

From my point of view, the test-docker-version is the latest version, isn't it?
If that's the case, changes in the mqtt-config do not take affect until a restart.

Nonetheless, a miss-config doesn't lead to a halt.
On the other hand, there is no log at all.

@theyosh
Copy link
Owner

theyosh commented Jan 28, 2022

No, not the docker version. Docker builds takes 2 hours... so I sparsely make them, just for me to test a new docker update. But it will not have the latest code. The last fix in mqtt is only available in the git source code

@theyosh
Copy link
Owner

theyosh commented Jan 28, 2022

So I fixed now the last issue with reloading the MQTT settings and losing the version number in the client id. That is now fixed and I would like to close this issue.

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
2 participants
@theyosh @kahuwi14