kizniche / Mycodo

An environmental monitoring and regulation system
http://kylegabriel.com/projects/
GNU General Public License v3.0
2.94k stars 492 forks source link

Can't start new threads #1261

Closed dylandn closed 1 year ago

dylandn commented 1 year ago

Describe the problem/bug

Recently updated from 8.14.2 to 8.15.1, and now things are going wrong. Daemon log shows the following errors when restarting the backend: `2023-01-15 10:57:53,145 - INFO - mycodo.daemon - Mycodo daemon terminated in 1.572 seconds

2023-01-15 10:59:33,999 - INFO - mycodo.outputs.on_off_mqtt_e37e45d4 - Initialized in 393.7 ms 2023-01-15 11:00:35,323 - INFO - mycodo.outputs.on_off_mqtt_0349fb7e - Initialized in 395.4 ms 2023-01-15 11:04:26,915 - INFO - mycodo.daemon - Mycodo daemon v8.15.1 starting 2023-01-15 11:04:28,219 - INFO - mycodo.outputs.pwm_gpio_226c297d - Output setup on Hardware pin 18 at 10000 Hertz 2023-01-15 11:04:30,264 - INFO - mycodo.outputs.pwm_gpio_226c297d - PWM set to 100.0 % duty cycle (last known value) 2023-01-15 11:04:30,272 - INFO - mycodo.outputs.pwm_gpio_226c297d - Initialized in 2423.6 ms 2023-01-15 11:04:30,737 - INFO - mycodo.outputs.pwm_gpio_c97f126a - Output setup on Any pin 25 at 8000 Hertz 2023-01-15 11:04:30,744 - INFO - mycodo.outputs.pwm_gpio_c97f126a - PWM set to 15.0 % duty cycle (user-specified value) 2023-01-15 11:04:30,744 - INFO - mycodo.outputs.pwm_gpio_c97f126a - Initialized in 468.2 ms 2023-01-15 11:04:31,261 - INFO - mycodo.outputs.on_off_mqtt_e3be67be - Initialized in 503.3 ms 2023-01-15 11:04:31,668 - INFO - mycodo.outputs.on_off_mqtt_a0cd3918 - Initialized in 403.5 ms 2023-01-15 11:04:32,067 - INFO - mycodo.outputs.on_off_mqtt_e37e45d4 - Initialized in 396.3 ms 2023-01-15 11:04:32,441 - INFO - mycodo.outputs.on_off_mqtt_249e3489 - Initialized in 371.5 ms 2023-01-15 11:04:32,816 - INFO - mycodo.outputs.on_off_mqtt_7a695808 - Initialized in 372.4 ms 2023-01-15 11:04:33,176 - INFO - mycodo.outputs.on_off_mqtt_ea5c1131 - Initialized in 357.4 ms 2023-01-15 11:04:33,545 - INFO - mycodo.outputs.on_off_mqtt_318e4c65 - Initialized in 366.9 ms 2023-01-15 11:04:33,919 - INFO - mycodo.outputs.on_off_mqtt_416ff31e - Initialized in 371.1 ms 2023-01-15 11:04:34,278 - INFO - mycodo.outputs.on_off_mqtt_e05b1d06 - Initialized in 356.5 ms 2023-01-15 11:04:34,659 - INFO - mycodo.outputs.on_off_mqtt_39e48078 - Initialized in 378.3 ms 2023-01-15 11:04:35,027 - INFO - mycodo.outputs.pwm_gpio_624f3d5a - Output setup on Any pin 24 at 10000 Hertz 2023-01-15 11:04:35,027 - INFO - mycodo.outputs.pwm_gpio_624f3d5a - Initialized in 365.8 ms 2023-01-15 11:04:35,435 - INFO - mycodo.outputs.on_off_gpio_e4df9b10 - Output setup on pin 17 and turned OFF (ON=HIGH) 2023-01-15 11:04:35,436 - INFO - mycodo.outputs.on_off_gpio_e4df9b10 - Initialized in 406.0 ms 2023-01-15 11:04:35,878 - INFO - mycodo.outputs.on_off_mqtt_0349fb7e - Initialized in 439.4 ms 2023-01-15 11:04:36,331 - INFO - mycodo.outputs.on_off_mqtt_d10d4dc3 - Initialized in 450.6 ms 2023-01-15 11:04:36,791 - INFO - mycodo.outputs.on_off_mqtt_11612b57 - Initialized in 457.2 ms 2023-01-15 11:04:37,261 - INFO - mycodo.outputs.on_off_mqtt_b395f396 - Initialized in 466.5 ms 2023-01-15 11:04:37,745 - INFO - mycodo.outputs.on_off_mqtt_ebd1a8ea - Initialized in 481.2 ms 2023-01-15 11:04:38,481 - INFO - mycodo.outputs.on_off_mqtt_874a4084 - Initialized in 732.9 ms 2023-01-15 11:04:38,482 - INFO - mycodo.controllers.controller_output - Activated in 11210.8 ms 2023-01-15 11:04:39,311 - INFO - mycodo.controllers.controller_conditional_2c500092 - Activated in 110.9 ms 2023-01-15 11:04:39,647 - INFO - mycodo.controllers.controller_conditional_052e72b9 - Activated in 109.5 ms 2023-01-15 11:04:39,976 - INFO - mycodo.controllers.controller_conditional_3553d5fe - Activated in 114.0 ms 2023-01-15 11:04:40,266 - INFO - mycodo.controllers.controller_conditional_96d3d014 - Activated in 88.5 ms 2023-01-15 11:04:40,267 - INFO - mycodo.daemon - All activated Conditional controllers started 2023-01-15 11:04:40,623 - INFO - mycodo.controllers.controller_trigger_ef50e5fc - Activated in 170.8 ms 2023-01-15 11:04:40,950 - INFO - mycodo.controllers.controller_trigger_a67fd251 - Activated in 145.6 ms 2023-01-15 11:04:41,291 - INFO - mycodo.controllers.controller_trigger_2daa51d9 - Activated in 145.1 ms 2023-01-15 11:04:41,618 - INFO - mycodo.controllers.controller_trigger_5202a2e2 - Activated in 144.8 ms 2023-01-15 11:04:41,958 - INFO - mycodo.controllers.controller_trigger_0d922894 - Activated in 143.4 ms 2023-01-15 11:04:42,292 - INFO - mycodo.controllers.controller_trigger_9fddf50d - Activated in 157.0 ms 2023-01-15 11:04:42,610 - INFO - mycodo.controllers.controller_trigger_0225a54a - Activated in 141.3 ms 2023-01-15 11:04:42,958 - INFO - mycodo.controllers.controller_trigger_ae40d540 - Activated in 142.3 ms 2023-01-15 11:04:42,958 - INFO - mycodo.daemon - All activated Trigger controllers started 2023-01-15 11:04:43,647 - INFO - mycodo.controllers.controller_input_5fd3fb8b - Activated in 468.8 ms 2023-01-15 11:04:44,288 - INFO - mycodo.controllers.controller_input_53726251 - Activated in 367.4 ms 2023-01-15 11:04:45,211 - INFO - mycodo.inputs.mqtt_paho_3110e60d - Connected to localhost as canopy/Temp 2023-01-15 11:04:45,213 - INFO - mycodo.controllers.controller_input_3110e60d - Activated in 403.7 ms 2023-01-15 11:04:45,768 - INFO - mycodo.daemon - All activated Input controllers started 2023-01-15 11:04:45,787 - INFO - mycodo.inputs.mqtt_paho_d6815d78 - Connected to localhost as canopy/humidity 2023-01-15 11:04:45,789 - INFO - mycodo.controllers.controller_input_d6815d78 - Activated in 397.8 ms 2023-01-15 11:04:46,225 - INFO - mycodo.controllers.controller_pid_257156bf - PID Settings: Device ID: d6815d78-bdda-4f7e-9b57-c16c4ec177f4, Measurement ID: 11ea9e5c-d4fd-4bc9-b855-f074709a2b91, Direction: lower, Period: 15.0, Setpoint: 60.0, Band: 0.2, Kp: 1.5, Ki: 0.1, Kd: 5.0, Integrator Min: -100.0, Integrator Max 100.0, Output Raise: None, Output Raise Channel: None, Output Raise Type: None, Output Raise Min On: 0.0, Output Raise Max On: 0.0, Output Raise Min Off: 0.0, Output Raise Always Min: False, Output Lower: 226c297d-9074-4ba3-afe2-76523d8233ca, Output Lower Channel: 0, Output Lower Type: pwm, Output Lower Min On: 0.0, Output Lower Max On: 100.0, Output Lower Min Off: 0.0, Output Lower Always Min: False, Setpoint Tracking Type: , Setpoint Tracking ID: 2023-01-15 11:04:46,226 - INFO - mycodo.controllers.controller_pid_257156bf - Activated in 268.5 ms 2023-01-15 11:04:46,509 - WARNING - mycodo.controllers.controller_pid_257156bf - No data from the specified time period returned from influxdb 2023-01-15 11:04:46,945 - INFO - mycodo.controllers.controller_pid_0e4f6a24 - PID Settings: Device ID: 3110e60d-2909-41be-ae73-1ed0157dc564, Measurement ID: aec3bc52-9cbf-4cc3-b2dc-0d6adb4137ef, Direction: raise, Period: 4.0, Setpoint: 20.0, Band: 0.1, Kp: 5.8, Ki: 0.07, Kd: 2.5, Integrator Min: -100.0, Integrator Max 40.0, Output Raise: e4df9b10-7148-4068-9bf9-22cf3dc408ba, Output Raise Channel: 0, Output Raise Type: on_off, Output Raise Min On: 0.0, Output Raise Max On: 0.0, Output Raise Min Off: 0.0, Output Raise Always Min: False, Output Lower: None, Output Lower Channel: None, Output Lower Type: None, Output Lower Min On: 0.0, Output Lower Max On: 0.0, Output Lower Min Off: 0.0, Output Lower Always Min: False, Setpoint Tracking Type: , Setpoint Tracking ID: 2023-01-15 11:04:46,946 - INFO - mycodo.controllers.controller_pid_0e4f6a24 - Activated in 446.4 ms 2023-01-15 11:04:46,946 - INFO - mycodo.daemon - All activated PID controllers started 2023-01-15 11:04:46,952 - INFO - mycodo.daemon - All activated Function controllers started 2023-01-15 11:04:47,212 - WARNING - mycodo.controllers.controller_pid_0e4f6a24 - No data from the specified time period returned from influxdb 2023-01-15 11:04:51,502 - WARNING - mycodo.controllers.controller_pid_0e4f6a24 - No data from the specified time period returned from influxdb 2023-01-15 11:04:52,663 - INFO - mycodo.controllers.controller_widget - Activated in 5711.1 ms 2023-01-15 11:04:53,667 - INFO - mycodo.daemon - Mycodo daemon started in 26.751 seconds 2023-01-15 11:04:53,763 - INFO - mycodo.daemon - 74.31 MB RAM in use 2023-01-15 11:04:55,183 - WARNING - mycodo.controllers.controller_pid_0e4f6a24 - No data from the specified time period returned from influxdb 2023-01-15 11:05:44,305 - INFO - mycodo.controllers.controller_input_5fd3fb8b - Deactivated in 46.6 ms 2023-01-15 11:06:12,747 - INFO - mycodo.controllers.controller_conditional_2c500092 - Deactivated in 140.1 ms 2023-01-15 11:06:17,378 - INFO - mycodo.controllers.controller_conditional_052e72b9 - Deactivated in 0.1 ms 2023-01-15 11:06:35,198 - INFO - mycodo.controllers.controller_input_53726251 - Deactivated in 66.5 ms 2023-01-15 11:07:11,243 - WARNING - mycodo.controllers.controller_pid_0e4f6a24 - No data from the specified time period returned from influxdb 2023-01-15 11:07:15,179 - WARNING - mycodo.controllers.controller_pid_0e4f6a24 - No data from the specified time period returned from influxdb 2023-01-15 11:07:16,519 - WARNING - mycodo.controllers.controller_pid_257156bf - No data from the specified time period returned from influxdb 2023-01-15 11:07:19,213 - WARNING - mycodo.controllers.controller_pid_0e4f6a24 - No data from the specified time period returned from influxdb 2023-01-15 11:07:23,151 - WARNING - mycodo.controllers.controller_pid_0e4f6a24 - No data from the specified time period returned from influxdb 2023-01-15 11:07:27,208 - WARNING - mycodo.controllers.controller_pid_0e4f6a24 - No data from the specified time period returned from influxdb 2023-01-15 11:07:31,275 - WARNING - mycodo.controllers.controller_pid_0e4f6a24 - No data from the specified time period returned from influxdb 2023-01-15 11:07:31,536 - WARNING - mycodo.controllers.controller_pid_257156bf - No data from the specified time period returned from influxdb 2023-01-15 11:07:31,544 - ERROR - mycodo.daemon - Could not turn output off: can't start new thread Traceback (most recent call last): File "/var/mycodo-root/mycodo/mycodo_daemon.py", line 735, in output_off return self.controller['Output'].output_on_off( File "/var/mycodo-root/mycodo/controllers/controller_output.py", line 299, in output_on_off return self.output[output_id].output_on_off( File "/var/mycodo-root/mycodo/outputs/base_output.py", line 390, in output_on_off ret_value = self.output_switch('off', output_type=output_type, output_channel=output_channel) File "/home/pi/Mycodo/mycodo/outputs/pwm_gpio.py", line 290, in output_switch add_measurements_influxdb(self.unique_id, measure_dict) File "/var/mycodo-root/mycodo/utils/influx.py", line 172, in add_measurements_influxdb write_db.start() File "/usr/lib/python3.9/threading.py", line 874, in start _start_new_thread(self._bootstrap, ()) RuntimeError: can't start new thread 2023-01-15 11:07:35,225 - WARNING - mycodo.controllers.controller_pid_0e4f6a24 - No data from the specified time period returned from influxdb 2023-01-15 11:07:36,170 - ERROR - mycodo.inputs.mqtt_paho_d6815d78 - Error processing message payload '59.2': can't start new thread 2023-01-15 11:07:38,775 - ERROR - mycodo.inputs.mqtt_paho_d6815d78 - Error processing message payload '59.2': can't start new thread 2023-01-15 11:07:39,312 - WARNING - mycodo.controllers.controller_pid_0e4f6a24 - No data from the specified time period returned from influxdb 2023-01-15 11:07:41,360 - ERROR - mycodo.inputs.mqtt_paho_3110e60d - Error processing message payload '19.5': can't start new thread 2023-01-15 11:07:41,368 - ERROR - mycodo.inputs.mqtt_paho_d6815d78 - Error processing message payload '59.3': can't start new thread 2023-01-15 11:07:43,210 - WARNING - mycodo.controllers.controller_pid_0e4f6a24 - No data from the specified time period returned from influxdb 2023-01-15 11:07:43,965 - ERROR - mycodo.inputs.mqtt_paho_d6815d78 - Error processing message payload '59.4': can't start new thread 2023-01-15 11:07:46,493 - WARNING - mycodo.controllers.controller_pid_257156bf - No data from the specified time period returned from influxdb 2023-01-15 11:07:46,579 - ERROR - mycodo.inputs.mqtt_paho_3110e60d - Error processing message payload '19.5': can't start new thread 2023-01-15 11:07:46,580 - ERROR - mycodo.inputs.mqtt_paho_d6815d78 - Error processing message payload '59.4': can't start new thread 2023-01-15 11:07:47,172 - WARNING - mycodo.controllers.controller_pid_0e4f6a24 - No data from the specified time period returned from influxdb 2023-01-15 11:07:49,153 - ERROR - mycodo.inputs.mqtt_paho_3110e60d - Error processing message payload '19.5': can't start new thread 2023-01-15 11:07:49,160 - ERROR - mycodo.inputs.mqtt_paho_d6815d78 - Error processing message payload '59.5': can't start new thread 2023-01-15 11:07:50,745 - ERROR - mycodo.daemon - Could not turn output off: can't start new thread Traceback (most recent call last): File "/var/mycodo-root/mycodo/mycodo_daemon.py", line 735, in output_off return self.controller['Output'].output_on_off( File "/var/mycodo-root/mycodo/controllers/controller_output.py", line 299, in output_on_off return self.output[output_id].output_on_off( File "/var/mycodo-root/mycodo/outputs/base_output.py", line 444, in output_on_off write_db.start() File "/usr/lib/python3.9/threading.py", line 874, in start _start_new_thread(self._bootstrap, ()) RuntimeError: can't start new thread 2023-01-15 11:07:51,176 - WARNING - mycodo.controllers.controller_pid_0e4f6a24 - No data from the specified time period returned from influxdb 2023-01-15 11:07:55,277 - WARNING - mycodo.controllers.controller_pid_0e4f6a24 - No data from the specified time period returned from influxdb 2023-01-15 11:07:59,260 - WARNING - mycodo.controllers.controller_pid_0e4f6a24 - No data from the specified time period returned from influxdb 2023-01-15 11:08:01,491 - WARNING - mycodo.controllers.controller_pid_257156bf - No data from the specified time period returned from influxdb 2023-01-15 11:08:03,873 - WARNING - mycodo.controllers.controller_pid_0e4f6a24 - No data from the specified time period returned from influxdb 2023-01-15 11:08:07,391 - WARNING - mycodo.controllers.controller_pid_0e4f6a24 - No data from the specified time period returned from influxdb 2023-01-15 11:08:09,007 - ERROR - mycodo.inputs.mqtt_paho_3110e60d - Error processing message payload '19.5': can't start new thread 2023-01-15 11:08:09,012 - ERROR - mycodo.inputs.mqtt_paho_d6815d78 - Error processing message payload '60.5': can't start new thread 2023-01-15 11:08:11,230 - WARNING - mycodo.controllers.controller_pid_0e4f6a24 - No data from the specified time period returned from influxdb 2023-01-15 11:08:11,616 - ERROR - mycodo.inputs.mqtt_paho_d6815d78 - Error processing message payload '60.5': can't start new thread 2023-01-15 11:08:14,218 - ERROR - mycodo.inputs.mqtt_paho_d6815d78 - Error processing message payload '60.6': can't start new thread 2023-01-15 11:08:15,169 - WARNING - mycodo.controllers.controller_pid_0e4f6a24 - No data from the specified time period returned from influxdb 2023-01-15 11:08:16,579 - WARNING - mycodo.controllers.controller_pid_257156bf - No data from the specified time period returned from influxdb 2023-01-15 11:08:16,587 - ERROR - mycodo.daemon - Could not turn output off: can't start new thread Traceback (most recent call last): File "/var/mycodo-root/mycodo/mycodo_daemon.py", line 735, in output_off return self.controller['Output'].output_on_off( File "/var/mycodo-root/mycodo/controllers/controller_output.py", line 299, in output_on_off return self.output[output_id].output_on_off( File "/var/mycodo-root/mycodo/outputs/base_output.py", line 390, in output_on_off ret_value = self.output_switch('off', output_type=output_type, output_channel=output_channel) File "/home/pi/Mycodo/mycodo/outputs/pwm_gpio.py", line 290, in output_switch add_measurements_influxdb(self.unique_id, measure_dict) File "/var/mycodo-root/mycodo/utils/influx.py", line 172, in add_measurements_influxdb write_db.start() File "/usr/lib/python3.9/threading.py", line 874, in start _start_new_thread(self._bootstrap, ()) RuntimeError: can't start new thread 2023-01-15 11:08:16,810 - ERROR - mycodo.inputs.mqtt_paho_3110e60d - Error processing message payload '19.5': can't start new thread 2023-01-15 11:08:16,818 - ERROR - mycodo.inputs.mqtt_paho_d6815d78 - Error processing message payload '60.7': can't start new thread 2023-01-15 11:08:19,224 - WARNING - mycodo.controllers.controller_pid_0e4f6a24 - No data from the specified time period returned from influxdb 2023-01-15 11:08:19,412 - ERROR - mycodo.inputs.mqtt_paho_d6815d78 - Error processing message payload '60.8': can't start new thread 2023-01-15 11:08:23,207 - WARNING - mycodo.controllers.controller_pid_0e4f6a24 - No data from the specified time period returned from influxdb 2023-01-15 11:08:24,623 - ERROR - mycodo.inputs.mqtt_paho_d6815d78 - Error processing message payload '61.0': can't start new thread 2023-01-15 11:08:27,169 - WARNING - mycodo.controllers.controller_pid_0e4f6a24 - No data from the specified time period returned from influxdb 2023-01-15 11:08:27,250 - ERROR - mycodo.inputs.mqtt_paho_d6815d78 - Error processing message payload '61.0': can't start new thread 2023-01-15 11:08:29,847 - ERROR - mycodo.inputs.mqtt_paho_d6815d78 - Error processing message payload '61.1': can't start new thread 2023-01-15 11:08:31,237 - WARNING - mycodo.controllers.controller_pid_0e4f6a24 - No data from the specified time period returned from influxdb 2023-01-15 11:08:31,538 - WARNING - mycodo.controllers.controller_pid_257156bf - No data from the specified time period returned from influxdb 2023-01-15 11:08:31,545 - ERROR - mycodo.daemon - Could not turn output off: can't start new thread Traceback (most recent call last): File "/var/mycodo-root/mycodo/mycodo_daemon.py", line 735, in output_off return self.controller['Output'].output_on_off( File "/var/mycodo-root/mycodo/controllers/controller_output.py", line 299, in output_on_off return self.output[output_id].output_on_off( File "/var/mycodo-root/mycodo/outputs/base_output.py", line 390, in output_on_off ret_value = self.output_switch('off', output_type=output_type, output_channel=output_channel) File "/home/pi/Mycodo/mycodo/outputs/pwm_gpio.py", line 290, in output_switch add_measurements_influxdb(self.unique_id, measure_dict) File "/var/mycodo-root/mycodo/utils/influx.py", line 172, in add_measurements_influxdb write_db.start() File "/usr/lib/python3.9/threading.py", line 874, in start _start_new_thread(self._bootstrap, ()) RuntimeError: can't start new thread 2023-01-15 11:08:32,400 - ERROR - mycodo.inputs.mqtt_paho_3110e60d - Error processing message payload '19.6': can't start new thread 2023-01-15 11:08:32,415 - ERROR - mycodo.inputs.mqtt_paho_d6815d78 - Error processing message payload '61.2': can't start new thread 2023-01-15 11:08:35,014 - ERROR - mycodo.inputs.mqtt_paho_d6815d78 - Error processing message payload '61.3': can't start new thread 2023-01-15 11:08:35,240 - WARNING - mycodo.controllers.controller_pid_0e4f6a24 - No data from the specified time period returned from influxdb 2023-01-15 11:08:37,612 - ERROR - mycodo.inputs.mqtt_paho_d6815d78 - Error processing message payload '61.3': can't start new thread 2023-01-15 11:08:39,303 - WARNING - mycodo.controllers.controller_pid_0e4f6a24 - No data from the specified time period returned from influxdb 2023-01-15 11:08:40,201 - ERROR - mycodo.inputs.mqtt_paho_3110e60d - Error processing message payload '19.5': can't start new thread 2023-01-15 11:08:40,208 - ERROR - mycodo.inputs.mqtt_paho_d6815d78 - Error processing message payload '61.4': can't start new thread 2023-01-15 11:08:42,808 - ERROR - mycodo.inputs.mqtt_paho_d6815d78 - Error processing message payload '61.5': can't start new thread 2023-01-15 11:08:43,156 - WARNING - mycodo.controllers.controller_pid_0e4f6a24 - No data from the specified time period returned from influxdb 2023-01-15 11:08:45,408 - ERROR - mycodo.inputs.mqtt_paho_3110e60d - Error processing message payload '19.6': can't start new thread 2023-01-15 11:08:45,463 - ERROR - mycodo.inputs.mqtt_paho_d6815d78 - Error processing message payload '61.6': can't start new thread 2023-01-15 11:08:46,558 - WARNING - mycodo.controllers.controller_pid_257156bf - No data from the specified time period returned from influxdb 2023-01-15 11:08:47,175 - WARNING - mycodo.controllers.controller_pid_0e4f6a24 - No data from the specified time period returned from influxdb 2023-01-15 11:08:48,000 - ERROR - mycodo.inputs.mqtt_paho_3110e60d - Error processing message payload '19.6': can't start new thread 2023-01-15 11:08:48,008 - ERROR - mycodo.inputs.mqtt_paho_d6815d78 - Error processing message payload '61.6': can't start new thread 2023-01-15 11:08:50,608 - ERROR - mycodo.inputs.mqtt_paho_d6815d78 - Error processing message payload '61.7': can't start new thread 2023-01-15 11:08:50,610 - ERROR - mycodo.inputs.mqtt_paho_3110e60d - Error processing message payload '19.6': can't start new thread 2023-01-15 11:08:50,628 - ERROR - mycodo.daemon - Could not turn output off: can't start new thread Traceback (most recent call last): File "/var/mycodo-root/mycodo/mycodo_daemon.py", line 735, in output_off return self.controller['Output'].output_on_off( File "/var/mycodo-root/mycodo/controllers/controller_output.py", line 299, in output_on_off return self.output[output_id].output_on_off( File "/var/mycodo-root/mycodo/outputs/base_output.py", line 444, in output_on_off write_db.start() File "/usr/lib/python3.9/threading.py", line 874, in start _start_new_thread(self._bootstrap, ()) RuntimeError: can't start new thread 2023-01-15 11:08:51,191 - WARNING - mycodo.controllers.controller_pid_0e4f6a24 - No data from the specified time period returned from influxdb 2023-01-15 11:08:55,276 - WARNING - mycodo.controllers.controller_pid_0e4f6a24 - No data from the specified time period returned from influxdb 2023-01-15 11:08:59,240 - WARNING - mycodo.controllers.controller_pid_0e4f6a24 - No data from the specified time period returned from influxdb 2023-01-15 11:09:01,456 - WARNING - mycodo.controllers.controller_pid_257156bf - No data from the specified time period returned from influxdb 2023-01-15 11:09:03,886 - WARNING - mycodo.controllers.controller_pid_0e4f6a24 - No data from the specified time period returned from influxdb 2023-01-15 11:09:07,300 - WARNING - mycodo.controllers.controller_pid_0e4f6a24 - No data from the specified time period returned from influxdb 2023-01-15 11:09:09,001 - ERROR - mycodo.inputs.mqtt_paho_3110e60d - Error processing message payload '19.6': can't start new thread 2023-01-15 11:09:09,012 - ERROR - mycodo.inputs.mqtt_paho_d6815d78 - Error processing message payload '62.3': can't start new thread`

Yet I only see 3 python processes running, and the total number of processes running is only 110.

Versions:

kizniche commented 1 year ago

Did you run out of RAM/Swap?

dylandn commented 1 year ago

Correction, there are many many python processes: python(758)-+-{python}(760) |-{python}(761) |-{python}(762) |-{python}(763) |-{python}(764) |-{python}(765) |-{python}(766) |-{python}(771) |-{python}(774) |-{python}(779) |-{python}(796) |-{python}(805) |-{python}(806) |-{python}(807) |-{python}(808) |-{python}(809) |-{python}(810) |-{python}(811) |-{python}(812) |-{python}(813) |-{python}(814) |-{python}(815) |-{python}(817) |-{python}(819) |-{python}(821) |-{python}(823) |-{python}(825) |-{python}(827) |-{python}(891) |-{python}(895) |-{python}(896) |-{python}(897) |-{python}(904) |-{python}(905) |-{python}(908) |-{python}(909) |-{python}(912) |-{python}(913) |-{python}(914) |-{python}(918) |-{python}(919) |-{python}(922) |-{python}(923) |-{python}(924) |-{python}(928) |-{python}(929) |-{python}(935) |-{python}(936) |-{python}(939) |-{python}(940) |-{python}(941) |-{python}(942) |-{python}(944) |-{python}(949) |-{python}(951) |-{python}(952) |-{python}(955) |-{python}(956) |-{python}(957) |-{python}(961) |-{python}(962) |-{python}(968) |-{python}(969) |-{python}(972) |-{python}(973) |-{python}(974) |-{python}(978) |-{python}(979) |-{python}(982) |-{python}(983) |-{python}(984) |-{python}(988) |-{python}(989) |-{python}(992) |-{python}(993) |-{python}(996) |-{python}(997) |-{python}(1007) |-{python}(1023) |-{python}(1024) |-{python}(1025) |-{python}(1033) |-{python}(1034) |-{python}(1037) |-{python}(1038) |-{python}(1039) |-{python}(1040) |-{python}(1043) |-{python}(1049) |-{python}(1068) |-{python}(1069) |-{python}(1071) |-{python}(1084) |-{python}(1085) |-{python}(1087) |-{python}(1090) |-{python}(1091) |-{python}(1094) |-{python}(1096) |-{python}(1099) |-{python}(1103) |-{python}(1127) |-{python}(1128) |-{python}(1131) |-{python}(1132) |-{python}(1133) |-{python}(1137) |-{python}(1138) |-{python}(1141) -{python}(1142)`

dylandn commented 1 year ago

As of right now with 240 python processes, I'm still at 237M used and 388M free.

kizniche commented 1 year ago

It looks like it's an issue with the 'threading' Python module, not Mycodo. I've never received this error before, so don't have any experience myself with it.

kizniche commented 1 year ago

You have a lot of MQTT Outputs. You may want to consider making a custom output that runs all of them so it only uses one thread instead of the many currently needed for all your MQTT Outputs. That would go a long way in reducing your thread usage, since this is likely due to resource issues in creating new threads.

kizniche commented 1 year ago

I have an idea for how to make a new MQTT Output that can configure publishing a variable number of MQTT topics. I don't know if/when I'll have time to build something like that, but it does seem like the right direction to solve your issue.

kizniche commented 1 year ago

A quick solution may be to increase the number of threads allowed: https://stackoverflow.com/a/65030992/4731724

dylandn commented 1 year ago

I've attempted to increase the nproc limit as described there, the old limit was 7262, to 14000 but on reboot, it's still 7262. Weird.

dylandn commented 1 year ago

Something really weird going on here. I have two MQTT inputs. With debug turned on for these inputs, I can see the data received regularly in the daemon log, every 3 seconds. I also have an MQTT client on my phone that shows MQTT data being received by Mosquitto running on the pi. Yet when I'm in the Live Measurements page, the data shows a timestamp that is 8 minutes behind, despite fresher measurements being available.

[edit] now 11 minutes behind, the lag seems to increase

dylandn commented 1 year ago

I've disabled all functions and deleted some of my unused MQTT outputs. As of right now with only the two MQTT inputs running, I am watching the number of python processes reported by the /info page (pstree -p xyz) increase slowly.

One of my previously functional PID functions is now reporting

Error(s): Error getting Function status: Traceback (most recent call last): File "/var/mycodo-root/mycodo/mycodo_daemon.py", line 491, in function_status return self.controller["PID"][function_id].function_status() File "/var/mycodo-root/mycodo/controllers/controller_pid.py", line 942, in function_status total = self.PID_Controller.P_value + self.PID_Controller.I_value + self.PID_Controller.D_value TypeError: unsupported operand type(s) for +: 'NoneType' and 'NoneType'

In addition to reporting:

2023-01-15 15:14:14,254 - WARNING - mycodo.controllers.controller_pid_257156bf - No data from the specified time period returned from influxdb 2023-01-15 15:14:14,255 - DEBUG - mycodo.controllers.controller_pid_257156bf - Last measurement unsuccessful. Turning outputs off.

Even though the log clearly shows data received every 3 seconds.

dylandn commented 1 year ago

I've watched the number of python threads (pstree -p xyz) slowly increase to 240 and that is when the logs started showing errors in processing message payloads. restarting the backend will reset the python process to 4, and it'll slowly climb back up to 240.

dylandn commented 1 year ago

Maybe this is a separate issue, but I am setting up a new rpi4 from scratch with mycodo, I've set up an MQTT input to receive MQTT values from mosquitto running on my existing Rpi3. In the rpi4 logs, the input debug shows it is receiving data from the rpi3, yet no data is shown in the Live Measurement page. The Asynchronous graph shows no data at all, despite 5 minutes of measurements at 3 seconds each.

I don't understand why I'm having so many issues.

Back on my old rPi3, I've disabled all inputs and all functions, then restarted the backend. The number of python processes is 12 and it does not change at all. I enable one MQTT input and now the number of python processes is climbing again. After disabling that one input, the number of python processes is slowly shrinking back to 12.

dylandn commented 1 year ago

Interesting. If I enable a non-mqtt input, the python processes does not creep up, it's only by enabling the mqtt input that starts the issue.

kizniche commented 1 year ago

Do you have debug log level enabled for the Input? Debug logs will likely give an indication of what is going on with the Input measurements.

kizniche commented 1 year ago

Try upgrading from paho-mqtt 1.5.1 to 1.6.1 and restart the daemon with the commands:

~/Mycodo/env/bin/pip install paho-mqtt==1.6.1 && sudo service mycodo restart

dylandn commented 1 year ago

I do have input debug on, and there's nothing to suggest there's a problem there:

2023-01-15 18:44:29,201 - INFO - mycodo.inputs.mqtt_paho_d6815d78 - Connected to localhost as canopy/humidity 2023-01-15 18:44:29,207 - DEBUG - mycodo.inputs.mqtt_paho_d6815d78 - Subscribing to MQTT topic 'canopy/humidity' 2023-01-15 18:44:29,216 - DEBUG - mycodo.inputs.mqtt_paho_d6815d78 - Connected to 'None'. Return code: 0 2023-01-15 18:44:29,217 - DEBUG - mycodo.inputs.mqtt_paho_d6815d78 - Subscribed to mqtt topic: None, 1, (0,) 2023-01-15 18:44:29,218 - INFO - mycodo.controllers.controller_input_d6815d78 - Activated in 848.8 ms 2023-01-15 18:44:29,251 - DEBUG - mycodo.inputs.mqtt_paho_3110e60d - Client created with ID canopy/Temp 2023-01-15 18:44:29,252 - DEBUG - mycodo.controllers.controller_input_3110e60d - Detected as listener. Starting listener thread. 2023-01-15 18:44:29,253 - DEBUG - mycodo.inputs.mqtt_paho_3110e60d - Connecting MQTT callback functions 2023-01-15 18:44:29,254 - DEBUG - mycodo.inputs.mqtt_paho_3110e60d - MQTT callback functions connected 2023-01-15 18:44:29,269 - INFO - mycodo.inputs.mqtt_paho_3110e60d - Connected to localhost as canopy/Temp 2023-01-15 18:44:29,276 - DEBUG - mycodo.inputs.mqtt_paho_3110e60d - Subscribing to MQTT topic 'canopy/temperature' 2023-01-15 18:44:29,280 - DEBUG - mycodo.inputs.mqtt_paho_3110e60d - Connected to 'None'. Return code: 0 2023-01-15 18:44:29,282 - DEBUG - mycodo.inputs.mqtt_paho_3110e60d - Subscribed to mqtt topic: None, 1, (0,) 2023-01-15 18:44:29,289 - INFO - mycodo.controllers.controller_input_3110e60d - Activated in 892.2 ms 2023-01-15 18:44:31,341 - DEBUG - mycodo.inputs.mqtt_paho_3110e60d - Received message: topic: canopy/temperature, payload: 16.2 2023-01-15 18:44:31,341 - DEBUG - mycodo.inputs.mqtt_paho_3110e60d - Found channel 0 with topic 'canopy/temperature' 2023-01-15 18:44:31,342 - DEBUG - mycodo.inputs.mqtt_paho_3110e60d - Payload represents a float: 16.2 2023-01-15 18:44:31,347 - DEBUG - mycodo.inputs.mqtt_paho_3110e60d - Adding measurement to influxdb: {0: {'measurement': 'temperature', 'unit': 'C', 'value': 16.2, 'timestamp_utc': datetime.datetime(2023, 1, 16, 2, 44, 31, 341752)}} 2023-01-15 18:44:31,348 - DEBUG - mycodo.inputs.mqtt_paho_d6815d78 - Received message: topic: canopy/humidity, payload: 69.6 2023-01-15 18:44:31,349 - DEBUG - mycodo.inputs.mqtt_paho_d6815d78 - Found channel 0 with topic 'canopy/humidity' 2023-01-15 18:44:31,353 - DEBUG - mycodo.inputs.mqtt_paho_d6815d78 - Payload represents a float: 69.6 2023-01-15 18:44:31,358 - DEBUG - mycodo.inputs.mqtt_paho_d6815d78 - Adding measurement to influxdb: {0: {'measurement': 'humidity', 'unit': 'percent', 'value': 69.6, 'timestamp_utc': datetime.datetime(2023, 1, 16, 2, 44, 31, 349197)}} 2023-01-15 18:44:33,941 - DEBUG - mycodo.inputs.mqtt_paho_3110e60d - Received message: topic: canopy/temperature, payload: 16.2 2023-01-15 18:44:33,942 - DEBUG - mycodo.inputs.mqtt_paho_3110e60d - Found channel 0 with topic 'canopy/temperature' 2023-01-15 18:44:33,943 - DEBUG - mycodo.inputs.mqtt_paho_3110e60d - Payload represents a float: 16.2 2023-01-15 18:44:33,951 - DEBUG - mycodo.inputs.mqtt_paho_3110e60d - Adding measurement to influxdb: {0: {'measurement': 'temperature', 'unit': 'C', 'value': 16.2, 'timestamp_utc': datetime.datetime(2023, 1, 16, 2, 44, 33, 942309)}} 2023-01-15 18:44:33,952 - DEBUG - mycodo.inputs.mqtt_paho_d6815d78 - Received message: topic: canopy/humidity, payload: 69.6 2023-01-15 18:44:33,959 - DEBUG - mycodo.inputs.mqtt_paho_d6815d78 - Found channel 0 with topic 'canopy/humidity' 2023-01-15 18:44:33,961 - DEBUG - mycodo.inputs.mqtt_paho_d6815d78 - Payload represents a float: 69.6 2023-01-15 18:44:33,970 - DEBUG - mycodo.inputs.mqtt_paho_d6815d78 - Adding measurement to influxdb: {0: {'measurement': 'humidity', 'unit': 'percent', 'value': 69.6, 'timestamp_utc': datetime.datetime(2023, 1, 16, 2, 44, 33, 959702)}}

Upgraded paho-mqtt, process count still creeps upwards, and the Live Measurements still lags behind.

I've started over on the installation on mycodo on my rpi4, second time must be a charm because it is now properly storing and reporting mqtt measurements. So I'm going to finish that and retire the rpi3.

dylandn commented 1 year ago

The rPi4 is up and running, but one of my conditional functions isn't working. This function used to work fine.

Full Conditional code:

1: import os 2: import sys 3: sys.path.append(os.path.abspath('/var/mycodo-root')) 4: from mycodo.controllers.base_conditional import AbstractConditional 5: from mycodo.mycodo_client import DaemonControl 6: control = DaemonControl(pyro_timeout=30.0) 7: 8: from time import time 9: 10: class ConditionalRun(AbstractConditional): 11: def init(self, logger, function_id, message): 12: super().init(logger, function_id, message, timeout=30.0) 13: 14: self.logger = logger 15: self.function_id = function_id 16: self.variables = {} 17: self.message = message 18: self.running = True 19: 20: 21: def conditional_code_run(self): 22: measurement = self.condition("2914926f-bf6b-4ded-bec6-251ec9c5f515") 23: 24: if measurement is None: 25: self.run_action("a01a75bd-d6a8-4f5c-9f91-f2746eba7342") 26: time.sleep(6) 27: self.run_action("9f5533fa-d453-4984-a619-f395cd7a0a32") 28: 29: def function_status(self): 30: pass

Conditional code analysis:

***** Module mycodo.user_python_code.conditional_79e63b3f-d7a5-48cd-b5e8-9c22b8fb24e7 dietpi/Mycodo/mycodo/user_python_code/conditional_79e63b3f-d7a5-48cd-b5e8-9c22b8fb24e7.py:8:0: C0411: standard import "from time import time" should be placed before "from mycodo.controllers.base_conditional import AbstractConditional" (wrong-import-order)


Your code has been rated at 9.57/10 (previous run: 9.57/10, +0.00)

And in the logs:

2023-01-15 22:00:44,830 - ERROR - mycodo.controllers.controller_conditional_79e63b3f - Exception executing Run Python Code Traceback (most recent call last): File "/var/mycodo-root/mycodo/controllers/controller_conditional.py", line 183, in check_conditionals self.conditional_run.conditional_code_run() File "/home/dietpi/Mycodo/mycodo/user_python_code/conditional_79e63b3f-d7a5-48cd-b5e8-9c22b8fb24e7.py", line 26, in conditional_code_run time.sleep(6) AttributeError: 'builtin_function_or_method' object has no attribute 'sleep'

dylandn commented 1 year ago

And for some strange reason, the log files in /var/log/mycodo get cleaned out once in a while.

kizniche commented 1 year ago

AttributeError: 'builtin_function_or_method' object has no attribute 'sleep'

The code you are showing doesn't contain this function that's erroring, so it's another of your conditionals that's causing it. It seems you are attempting to call builtin_function_or_method.sleep() when sleep is not an attribute of that object.

Logs are periodically rotated with logrotate when they get to a certain size, so they are split into smaller logs for archival.

dylandn commented 1 year ago

This is my only Conditional that invokes sleep. I'm going to retire the AM2315 sensor that requires me to power cycle the esp8266 it's connected to, junk sensor.

I apologize for this disaster of an issue post, it's rambling and covers other issues. I'd be fine if you wish to delete it. I think the old rPi3 had accumulated too many issues and turned into an undebuggable mess.

kizniche commented 1 year ago

No problem. We've solved the original issue by determining a fresh install doesn't cause the problem anymore (which I guess doesn't solve the problem but at least we know whatever caused it is unrelated to the latest code).

As for the sleep issue, it's likely due to the import statement. It should be import time. See https://stackoverflow.com/questions/51466064/python-attributeerror-builtin-function-or-method-object-has-no-attribute-sl

dylandn commented 1 year ago

'import sleep' is what I had originally before it started with the errors, so I thought it needed 'from time' added but same error. Now the function seems to work, just pylint not giving me a perfect score.

logrotate seems to be rotating logs quite often, hard to debug when it's that often. This might be related to me building this rpi4 with DietPi instead of Raspbian. But now everything's working again. so, logs? shrug

Thank you!!!