kizniche / Mycodo

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

Every 2 days database becomes locked. System crashes. #1310

Open LucidEye opened 1 year ago

LucidEye commented 1 year ago

Describe the problem/bug

General problem: Mycodo database becomes locked after repeated errors in the daemon log. Mycodo then becomes extremely slow and unresponsive in the web interface, and SSH connection also becomes frozen or cannot connect at all. Only way to regain access to the Pi is a hard reboot.

Problem Details: The error that triggers this cascading failure is that suddenly, for no apparent reason, the bang bang controlling my VPD can no longer get the VPD measurement.
The Daemon log shows this error repeating for several minutes: 2023-05-30 20:56:13,281 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-05-30 20:56:25,178 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-05-30 20:56:28,343 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-05-30 20:56:33,517 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-05-30 20:56:38,339 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-05-30 20:57:06,705 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-05-30 20:57:08,305 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-05-30 20:57:13,369 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-05-30 20:57:18,303 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-05-30 20:57:23,607 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-05-30 20:57:50,292 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-05-30 20:57:56,882 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-05-30 20:57:58,221 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-05-30 20:58:03,455 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-05-30 20:58:28,880 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-05-30 20:58:33,467 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-05-30 20:58:38,402 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-05-30 20:58:43,315 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-05-30 20:59:08,419 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-05-30 20:59:13,652 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement

That VPD measurement is coming from the VPD Calculation Function, setup as shown: Screenshot at 2023-05-30 21-44-58

The temperature measurement for that VPD Function is being calculated from another math Function (Equation: Single Measurement) setup as shown: Screenshot at 2023-05-30 21-47-31

After the original bang-bang error happens, there is a series of repeating errors and then the system becomes unresponsive:

Traceback (most recent call last): File "/var/mycodo-root/mycodo/controllers/base_controller.py", line 81, in run self.loop() File "/var/mycodo-root/mycodo/controllers/controller_input.py", line 220, in loop measurements_dict = self.create_measurements_dict() File "/var/mycodo-root/mycodo/controllers/controller_input.py", line 418, in create_measurements_dict measurement = self.device_measurements.filter( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/query.py", line 2752, in first return self.limit(1)._iter().first() # type: ignore File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/query.py", line 2855, in _iter result: Union[ScalarResult[_T], Result[_T]] = self.session.execute( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/session.py", line 2229, in execute return self._execute_internal( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/session.py", line 2124, in _execute_internal result: Result[Any] = compile_state_cls.orm_execute_statement( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/context.py", line 253, in orm_execute_statement result = conn.execute( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1414, in execute return meth( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/sql/elements.py", line 486, in _execute_on_connection return connection._execute_clauseelement( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1638, in _execute_clauseelement ret = self._execute_context( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1842, in _execute_context return self._exec_single_context( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1983, in _exec_single_context self._handle_dbapi_exception( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 2326, in _handle_dbapi_exception raise sqlalchemy_exception.with_traceback(exc_info[2]) from e File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1964, in _exec_single_context self.dialect.do_execute( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/default.py", line 748, in do_execute cursor.execute(statement, parameters) sqlalchemy.exc.OperationalError: (sqlite3.OperationalError) database is locked [SQL: SELECT device_measurements.id AS device_measurements_id, device_measurements.unique_id AS device_measurements_unique_id, device_measurements.name AS device_measurements_name, device_measurements.device_type AS device_measurements_device_type, device_measurements.device_id AS device_measurements_device_id, device_measurements.is_enabled AS device_measurements_is_enabled, device_measurements.measurement AS device_measurements_measurement, device_measurements.measurement_type AS device_measurements_measurement_type, device_measurements.unit AS device_measurements_unit, device_measurements.channel AS device_measurements_channel, device_measurements.rescale_method AS device_measurements_rescale_method, device_measurements.rescale_equation AS device_measurements_rescale_equation, device_measurements.invert_scale AS device_measurements_invert_scale, device_measurements.rescaled_measurement AS device_measurements_rescaled_measurement, device_measurements.rescaled_unit AS device_measurements_rescaled_unit, device_measurements.scale_from_min AS device_measurements_scale_from_min, device_measurements.scale_from_max AS device_measurements_scale_from_max, device_measurements.scale_to_min AS device_measurements_scale_to_min, device_measurements.scale_to_max AS device_measurements_scale_to_max, device_measurements.conversion_id AS device_measurements_conversion_id FROM device_measurements WHERE device_measurements.device_id = ? AND device_measurements.channel = ? LIMIT ? OFFSET ?] [parameters: ('9ec8173c-5110-4851-8324-517f2c80277f', 0, 1, 0)] (Background on this error at: https://sqlalche.me/e/20/e3q8) 2023-05-30 21:00:21,121 - ERROR - mycodo.databases.utils - Error raised in session_scope. Session will be rolled back: db_uri='sqlite:////home/pi/Mycodo/databases/mycodo.db', error='(sqlite3.OperationalError) database is locked [SQL: SELECT conditional.id AS conditional_id, conditional.unique_id AS conditional_unique_id, conditional.name AS conditional_name, conditional.position_y AS conditional_position_y, conditional.is_activated AS conditional_is_activated, conditional.log_level_debug AS conditional_log_level_debug, conditional.conditional_statement AS conditional_conditional_statement, conditional.conditional_import AS conditional_conditional_import, conditional.conditional_initialize AS conditional_conditional_initialize, conditional.conditional_status AS conditional_conditional_status, conditional.period AS conditional_period, conditional.start_offset AS conditional_start_offset, conditional.pyro_timeout AS conditional_pyro_timeout, conditional.use_pylint AS conditional_use_pylint, conditional.message_include_code AS conditional_message_include_code, conditional.custom_options AS conditional_custom_options FROM conditional WHERE conditional.unique_id = ? LIMIT ? OFFSET ?] [parameters: ('31d0988f-3e3f-425e-89a9-2e14e830a3e3', 1, 0)] (Background on this error at: https://sqlalche.me/e/20/e3q8)' Traceback (most recent call last): File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1964, in _exec_single_context self.dialect.do_execute( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/default.py", line 748, in do_execute cursor.execute(statement, parameters) sqlite3.OperationalError: database is locked

The above exception was the direct cause of the following exception:

Traceback (most recent call last): File "/var/mycodo-root/mycodo/databases/utils.py", line 26, in session_scope yield session File "/var/mycodo-root/mycodo/utils/database.py", line 70, in db_retrieve_table_daemon return_table = return_table.first() File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/query.py", line 2752, in first return self.limit(1)._iter().first() # type: ignore File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/query.py", line 2855, in _iter result: Union[ScalarResult[_T], Result[_T]] = self.session.execute( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/session.py", line 2229, in execute return self._execute_internal( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/session.py", line 2124, in _execute_internal result: Result[Any] = compile_state_cls.orm_execute_statement( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/context.py", line 253, in orm_execute_statement result = conn.execute( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1414, in execute return meth( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/sql/elements.py", line 486, in _execute_on_connection return connection._execute_clauseelement( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1638, in _execute_clauseelement ret = self._execute_context( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1842, in _execute_context return self._exec_single_context( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1983, in _exec_single_context self._handle_dbapi_exception( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 2326, in _handle_dbapi_exception raise sqlalchemy_exception.with_traceback(exc_info[2]) from e File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1964, in _exec_single_context self.dialect.do_execute( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/default.py", line 748, in do_execute cursor.execute(statement, parameters) sqlalchemy.exc.OperationalError: (sqlite3.OperationalError) database is locked [SQL: SELECT conditional.id AS conditional_id, conditional.unique_id AS conditional_unique_id, conditional.name AS conditional_name, conditional.position_y AS conditional_position_y, conditional.is_activated AS conditional_is_activated, conditional.log_level_debug AS conditional_log_level_debug, conditional.conditional_statement AS conditional_conditional_statement, conditional.conditional_import AS conditional_conditional_import, conditional.conditional_initialize AS conditional_conditional_initialize, conditional.conditional_status AS conditional_conditional_status, conditional.period AS conditional_period, conditional.start_offset AS conditional_start_offset, conditional.pyro_timeout AS conditional_pyro_timeout, conditional.use_pylint AS conditional_use_pylint, conditional.message_include_code AS conditional_message_include_code, conditional.custom_options AS conditional_custom_options FROM conditional WHERE conditional.unique_id = ? LIMIT ? OFFSET ?] [parameters: ('31d0988f-3e3f-425e-89a9-2e14e830a3e3', 1, 0)] (Background on this error at: https://sqlalche.me/e/20/e3q8) 2023-05-30 21:01:32,406 - ERROR - mycodo.database - The Mycodo database is locked. Trying to access again in 1 second... 2023-05-30 21:01:31,422 - ERROR - mycodo.database - The Mycodo database is locked. Trying to access again in 1 second... 2023-05-30 21:01:32,190 - ERROR - mycodo.database - The Mycodo database is locked. Trying to access again in 1 second... 2023-05-30 21:01:32,208 - ERROR - mycodo.database - The Mycodo database is locked. Trying to access again in 1 second... 2023-05-30 21:01:32,222 - ERROR - mycodo.database - The Mycodo database is locked. Trying to access again in 1 second... 2023-05-30 21:01:32,239 - ERROR - mycodo.database - The Mycodo database is locked. Trying to access again in 1 second... 2023-05-30 21:01:32,246 - ERROR - mycodo.database - The Mycodo database is locked. Trying to access again in 1 second... 2023-05-30 21:01:32,264 - ERROR - mycodo.database - The Mycodo database is locked. Trying to access again in 1 second... 2023-05-30 21:01:32,270 - ERROR - mycodo.database - The Mycodo database is locked. Trying to access again in 1 second... 2023-05-30 21:01:32,290 - ERROR - mycodo.database - The Mycodo database is locked. Trying to access again in 1 second... 2023-05-30 21:01:32,297 - ERROR - mycodo.database - The Mycodo database is locked. Trying to access again in 1 second... 2023-05-30 21:01:32,316 - ERROR - mycodo.database - The Mycodo database is locked. Trying to access again in 1 second... 2023-05-30 21:01:32,324 - ERROR - mycodo.database - The Mycodo database is locked. Trying to access again in 1 second... 2023-05-30 21:01:32,326 - ERROR - mycodo.database - The Mycodo database is locked. Trying to access again in 1 second... 2023-05-30 21:01:32,345 - ERROR - mycodo.database - The Mycodo database is locked. Trying to access again in 1 second... 2023-05-30 21:01:32,355 - ERROR - mycodo.database - The Mycodo database is locked. Trying to access again in 1 second... 2023-05-30 21:01:32,395 - ERROR - mycodo.database - The Mycodo database is locked. Trying to access again in 1 second... 2023-05-30 21:01:29,281 - ERROR - mycodo.database - The Mycodo database is locked. Trying to access again in 1 second...

Versions:

Reproducibility

This problem seems to reproduce itself every few days (3-4 maybe). The system seems to be working just fine, then for some reason a repeating error appears in the daemon log, which triggers exceptions, which leads to the database becoming locked and Mycodo becoming unresponsive.
After a hard reboot to recover from this hang condition, the system will again run fine for a few days before the same problem occurs again.

Expected behavior

Expected behavior is that the system does not crash every couple of days for an unknown reason. I have not yet been able to determine why the VPD Function stops receiving the temperature from the Equation: Single Measurement Function.

I have since enabled Debug level logging on all of these functions and the input sensor generating the original temperature measurement to see if I can trace what is happening.

Any ideas why this might be happening?

LucidEye commented 1 year ago

Update: Mycodo is still "crashing". Everything will be running along just fine, then suddenly Mycodo stops getting a measurement... it seems random as to which measurement suddenly stops... sometimes it's the available RAM measurement, sometimes it's a bang-bang that can't get a measurement, but there are no real errors or tracebacks in the logs.... Mycodo just stops responding, I can't even SSH into the Pi to see what is happening... I have to pull the plug to reset it. This is now happening every 2-3 days. I have checked for any physical / electrical issues and found none. I haven't changed much except upgrading to the 64 bit OS and Influx 2.

LucidEye commented 1 year ago

Woke up this morning and Mycodo had crashed again.
System was unresponsive, could not SSH into the Pi or access the web GUI to see what the problem was.
Had to unplug the Pi to get it to reboot. The real problem is that the humidifier was stuck on for hours and the entire grow space was soaking wet again. This is on my live system, so it's really frustrating to not have it working reliably. This is still happening every 2 days now, and I can not figure out why. There are still no messages in the logs that indicate what is causing this to happen every 2 days. I feel there is a major bug somewhere. The green line is CPU load... for some unknown reason the CPU load starts to climb, and doesn't stop until the system crashes. Screenshot at 2023-06-12 07-51-31

The logs still show that the database is getting locked for some reason... what ever is causing this is what leads to this total system failure.

It seems like the cause is that for some reason Mycodo can not get measurement data from one or another input, and this causes a crash.

Here are some excerpts from the over 500,000 error lines I found in the daemon log this morning....

"2023-06-12 07:28:51,984 - ERROR - mycodo.inputs.rpi_cpu_gpu_temperature_9ec8173c - Error getting GPU temperature: [Errno 24] Too many open files"

"2023-06-12 07:21:02,636 - ERROR - mycodo.databases.utils - Error raised in session_scope. Session will be rolled back: db_uri='sqlite:////home/pi/Mycodo/databases/mycodo.db', error='(sqlite3.OperationalError) unable to open database file (Background on this error at: https://sqlalche.me/e/20/e3q8)'"

"The above exception was the direct cause of the following exception:

Traceback (most recent call last): File "/var/mycodo-root/mycodo/databases/utils.py", line 26, in session_scope yield session File "/var/mycodo-root/mycodo/utils/database.py", line 70, in db_retrieve_table_daemon return_table = return_table.first() File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/query.py", line 2752, in first return self.limit(1)._iter().first() # type: ignore File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/query.py", line 2855, in _iter result: Union[ScalarResult[_T], Result[_T]] = self.session.execute( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/session.py", line 2229, in execute return self._execute_internal( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/session.py", line 2114, in _execute_internal conn = self._connection_for_bind(bind) File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/session.py", line 1981, in _connection_for_bind return trans._connection_for_bind(engine, execution_options) File "", line 2, in _connection_for_bind File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/state_changes.py", line 137, in _go ret_value = fn(self, *arg, kw) File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/session.py", line 1108, in _connection_for_bind conn = bind.connect() File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 3251, in connect return self._connection_cls(self) File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 147, in init Connection._handle_dbapi_exception_noconnection( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 2413, in _handle_dbapi_exception_noconnection raise sqlalchemy_exception.with_traceback(exc_info[2]) from e File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 145, in init self._dbapi_connection = engine.raw_connection() File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 3275, in raw_connection return self.pool.connect() File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/pool/base.py", line 455, in connect return _ConnectionFairy._checkout(self) File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/pool/base.py", line 1271, in _checkout fairy = _ConnectionRecord.checkout(pool) File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/pool/base.py", line 719, in checkout rec = pool._do_get() File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/pool/impl.py", line 169, in _do_get self._dec_overflow() File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/util/langhelpers.py", line 147, in exit raise exc_value.with_traceback(exc_tb) File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/pool/impl.py", line 166, in _do_get return self._create_connection() File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/pool/base.py", line 396, in _create_connection return _ConnectionRecord(self) File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/pool/base.py", line 681, in init self.connect() File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/pool/base.py", line 906, in connect pool.logger.debug("Error on connect(): %s", e) File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/util/langhelpers.py", line 147, in exit raise exc_value.with_traceback(exc_tb) File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/pool/base.py", line 901, in __connect self.dbapi_connection = connection = pool._invoke_creator(self) File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/create.py", line 636, in connect return dialect.connect(*cargs, *cparams) File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/default.py", line 580, in connect return self.loaded_dbapi.connect(cargs, cparams) sqlalchemy.exc.OperationalError: (sqlite3.OperationalError) unable to open database file (Background on this error at: https://sqlalche.me/e/20/e3q8) 2023-06-12 07:20:48,455 - ERROR - mycodo.databases.utils - Error raised in session_scope. Session will be rolled back: db_uri='sqlite:////home/pi/Mycodo/databases/mycodo.db', error='(sqlite3.OperationalError) unable to open database file (Background on this error at: https://sqlalche.me/e/20/e3q8)'"

I really need to have this system running reliably again... I am in the middle of a grow and can not have the system crashing like this every 2 days.

LucidEye commented 1 year ago

I would upload the entire log file, but Github only allows 25MB max file size, and the log is now 60MB. Also, I can not directly open the log file in a text editor on my computer... I am getting an error that there is a problem with the character encoding of the file???? I can not use Mycodo to browse back through this file, because I need to view 1,000,000 lines of the log to get back to where the original error occurred, and the web gui crashes when trying to open that many lines. So I now have no way of even looking for the error. :-(

LucidEye commented 1 year ago

Woke up this morning, and the system has crashed again.... can not ssh in, can not access the web gui. This is now only 24 hours after the last crash. Had to pull the plug on the pi to get it to reboot. The logs show the same problem. What is causing this and how do I fix it?

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/pi/Mycodo/mycodo/user_python_code/conditional_a0417b2a-805d-4858-90b7-7e3f5151df7e.py", line 46, in conditional_code_run self.run_action("cba8014f", value={"payload": "0,0,0"}) File "/var/mycodo-root/mycodo/controllers/base_conditional.py", line 46, in run_action action = new_session.query(Actions).filter( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/query.py", line 2752, in first return self.limit(1)._iter().first() # type: ignore File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/query.py", line 2855, in _iter result: Union[ScalarResult[_T], Result[_T]] = self.session.execute( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/session.py", line 2229, in execute return self._execute_internal( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/session.py", line 2124, in _execute_internal result: Result[Any] = compile_state_cls.orm_execute_statement( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/context.py", line 253, in orm_execute_statement result = conn.execute( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1414, in execute return meth( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/sql/elements.py", line 486, in _execute_on_connection return connection._execute_clauseelement( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1638, in _execute_clauseelement ret = self._execute_context( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1842, in _execute_context return self._exec_single_context( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1983, in _exec_single_context self._handle_dbapi_exception( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 2326, in _handle_dbapi_exception raise sqlalchemy_exception.with_traceback(exc_info[2]) from e File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1964, in _exec_single_context self.dialect.do_execute( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/default.py", line 748, in do_execute cursor.execute(statement, parameters) sqlalchemy.exc.OperationalError: (sqlite3.OperationalError) database is locked [SQL: SELECT function_actions.id AS function_actions_id, function_actions.unique_id AS function_actions_unique_id, function_actions.function_id AS function_actions_function_id, function_actions.function_type AS function_actions_function_type, function_actions.action_type AS function_actions_action_type, function_actions.custom_options AS function_actions_custom_options, function_actions.pause_duration AS function_actions_pause_duration, function_actions.do_unique_id AS function_actions_do_unique_id, function_actions.do_action_string AS function_actions_do_action_string, function_actions.do_output_state AS function_actions_do_output_state, function_actions.do_output_amount AS function_actions_do_output_amount, function_actions.do_output_duration AS function_actions_do_output_duration, function_actions.do_output_pwm AS function_actions_do_output_pwm, function_actions.do_output_pwm2 AS function_actions_do_output_pwm2, function_actions.do_camera_duration AS function_actions_do_camera_duration, function_actions.remote AS function_actions_remote, function_actions.code AS function_actions_code, function_actions.send_times AS function_actions_send_times FROM function_actions WHERE (function_actions.unique_id LIKE ? || '%') LIMIT ? OFFSET ?] [parameters: ('cba8014f', 1, 0)] (Background on this error at: https://sqlalche.me/e/20/e3q8) 2023-06-13 07:00:56,864 - ERROR - mycodo - Daemon Error Traceback (most recent call last): File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1964, in _exec_single_context self.dialect.do_execute( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/default.py", line 748, in do_execute cursor.execute(statement, parameters) sqlite3.OperationalError: database is locked

The above exception was the direct cause of the following exception:

Traceback (most recent call last): File "/var/mycodo-root/mycodo/mycodo_daemon.py", line 163, in run self.check_all_timelapses(now) File "/var/mycodo-root/mycodo/mycodo_daemon.py", line 1023, in check_all_timelapses for each_camera in new_session.query(Camera).all(): File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/query.py", line 2697, in all return self._iter().all() # type: ignore File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/query.py", line 2855, in _iter result: Union[ScalarResult[_T], Result[_T]] = self.session.execute( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/session.py", line 2229, in execute return self._execute_internal( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/session.py", line 2124, in _execute_internal result: Result[Any] = compile_state_cls.orm_execute_statement( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/context.py", line 253, in orm_execute_statement result = conn.execute( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1414, in execute return meth( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/sql/elements.py", line 486, in _execute_on_connection return connection._execute_clauseelement( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1638, in _execute_clauseelement ret = self._execute_context( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1842, in _execute_context return self._exec_single_context( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1983, in _exec_single_context self._handle_dbapi_exception( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 2326, in _handle_dbapi_exception raise sqlalchemy_exception.with_traceback(exc_info[2]) from e File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1964, in _exec_single_context self.dialect.do_execute( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/default.py", line 748, in do_execute cursor.execute(statement, parameters) sqlalchemy.exc.OperationalError: (sqlite3.OperationalError) database is locked [SQL: SELECT camera.id AS camera_id, camera.unique_id AS camera_unique_id, camera.name AS camera_name, camera.library AS camera_library, camera.device AS camera_device, camera.opencv_device AS camera_opencv_device, camera.hflip AS camera_hflip, camera.vflip AS camera_vflip, camera.rotation AS camera_rotation, camera.brightness AS camera_brightness, camera.contrast AS camera_contrast, camera.exposure AS camera_exposure, camera.gain AS camera_gain, camera.hue AS camera_hue, camera.saturation AS camera_saturation, camera.white_balance AS camera_white_balance, camera.custom_options AS camera_custom_options, camera.output_id AS camera_output_id, camera.output_duration AS camera_output_duration, camera.cmd_pre_camera AS camera_cmd_pre_camera, camera.cmd_post_camera AS camera_cmd_post_camera, camera.stream_started AS camera_stream_started, camera.hide_still AS camera_hide_still, camera.hide_timelapse AS camera_hide_timelapse, camera.url_still AS camera_url_still, camera.url_stream AS camera_url_stream, camera.json_headers AS camera_json_headers, camera.show_preview AS camera_show_preview, camera.output_format AS camera_output_format, camera.timelapse_started AS camera_timelapse_started, camera.timelapse_paused AS camera_timelapse_paused, camera.timelapse_start_time AS camera_timelapse_start_time, camera.timelapse_end_time AS camera_timelapse_end_time, camera.timelapse_interval AS camera_timelapse_interval, camera.timelapse_next_capture AS camera_timelapse_next_capture, camera.timelapse_capture_number AS camera_timelapse_capture_number, camera.timelapse_last_file AS camera_timelapse_last_file, camera.timelapse_last_ts AS camera_timelapse_last_ts, camera.still_last_file AS camera_still_last_file, camera.still_last_ts AS camera_still_last_ts, camera.path_still AS camera_path_still, camera.path_timelapse AS camera_path_timelapse, camera.path_video AS camera_path_video, camera.width AS camera_width, camera.height AS camera_height, camera.resolution_stream_width AS camera_resolution_stream_width, camera.resolution_stream_height AS camera_resolution_stream_height, camera.stream_fps AS camera_stream_fps, camera.picamera_shutter_speed AS camera_picamera_shutter_speed, camera.picamera_sharpness AS camera_picamera_sharpness, camera.picamera_iso AS camera_picamera_iso, camera.picamera_awb AS camera_picamera_awb, camera.picamera_awb_gain_red AS camera_picamera_awb_gain_red, camera.picamera_awb_gain_blue AS camera_picamera_awb_gain_blue, camera.picamera_exposure_mode AS camera_picamera_exposure_mode, camera.picamera_meter_mode AS camera_picamera_meter_mode, camera.picamera_image_effect AS camera_picamera_image_effect FROM camera] (Background on this error at: https://sqlalche.me/e/20/e3q8) 2023-06-13 07:00:56,865 - ERROR - mycodo.database - The Mycodo database is locked. Trying to access again in 1 second... 2023-06-13 07:00:56,869 - ERROR - mycodo.database - The Mycodo database is locked. Trying to access again in 1 second... 2023-06-13 07:00:56,872 - ERROR - mycodo.database - The Mycodo database is locked. Trying to access again in 1 second... 2023-06-13 07:00:56,896 - ERROR - mycodo.database - The Mycodo database is locked. Trying to access again in 1 second... 2023-06-13 07:00:57,399 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:00:58,756 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:01:03,653 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:01:08,264 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:01:13,288 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:01:18,290 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:01:46,138 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:01:48,397 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:01:53,208 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:02:16,649 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:02:18,538 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:02:23,318 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:02:53,712 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:02:58,478 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:03:03,338 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:03:08,311 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:03:38,002 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:03:38,489 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:03:43,358 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:03:48,418 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:03:54,602 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:03:59,195 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:04:03,320 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:06:08,303 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:06:13,328 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:06:18,634 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:06:29,632 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:06:33,318 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:06:38,393 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:10:19,296 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:10:23,447 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:10:28,271 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:10:58,077 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:10:58,691 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:11:03,625 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:11:08,253 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:11:21,168 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:11:23,518 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:11:28,301 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:11:33,383 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:11:38,961 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:12:04,066 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:12:09,021 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:12:13,411 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:12:18,278 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:12:23,586 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:12:28,314 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:12:33,360 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:12:38,442 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:12:43,228 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:12:48,277 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:12:55,575 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:15:33,355 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:15:38,421 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:15:43,195 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:15:48,309 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:15:53,312 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:15:58,222 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:16:03,273 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:16:08,405 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:16:13,413 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:16:18,199 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:16:23,287 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:16:28,291 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:16:33,300 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:16:38,316 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:17:06,306 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:17:08,375 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:17:21,748 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:17:23,274 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:17:28,435 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:17:33,283 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:17:38,367 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:17:43,458 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:18:15,988 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:18:18,296 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:18:23,401 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:18:39,833 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:18:43,397 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:18:48,206 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:18:53,206 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:19:23,910 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:19:38,172 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:19:38,788 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:19:43,390 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:19:49,772 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:19:53,352 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:19:58,535 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:20:27,817 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:20:28,387 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:20:33,424 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:20:38,345 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:20:50,356 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:20:54,743 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:20:58,467 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:21:03,353 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:21:32,293 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:21:33,297 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:21:38,305 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:21:51,345 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:21:53,349 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:28:49,937 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:28:53,243 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:28:58,316 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:29:03,420 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:29:08,258 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:29:13,366 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:29:18,424 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:23:39,576 - INFO - mycodo - Mycodo daemon v8.15.8 starting 2023-06-13 07:23:39,596 - INFO - mycodo.pyro_daemon - Starting Pyro5 daemon 2023-06-13 07:23:40,300 - INFO - mycodo.outputs.on_off_gpio_cfaaccb0 - Output setup on pin 20 and turned OFF (ON=HIGH) 2023-06-13 07:23:40,301 - INFO - mycodo.outputs.on_off_gpio_cfaaccb0 - Initialized in 219.0 ms 2023-06-13 07:23:40,532 - INFO - mycodo.outputs.pwm_gpio_c0598a74 - Output setup on Any pin 18 at 22000 Hertz 2023-06-13 07:23:40,534 - INFO - mycodo.outputs.pwm_gpio_c0598a74 - PWM set to 30.0 % duty cycle (user-specified value) 2023-06-13 07:23:40,535 - INFO - mycodo.outputs.pwm_gpio_c0598a74 - Initialized in 232.6 ms 2023-06-13 07:23:40,851 - INFO - mycodo.outputs.on_off_gpio_d30253e9 - Output setup on pin 16 and turned OFF (ON=HIGH) 2023-06-13 07:23:40,853 - INFO - mycodo.outputs.on_off_gpio_d30253e9 - Initialized in 313.1 ms 2023-06-13 07:23:41,263 - INFO - mycodo.outputs.on_off_gpio_4a216c40 - Output setup on pin 21 and turned OFF (ON=HIGH) 2023-06-13 07:23:41,264 - INFO - mycodo.outputs.on_off_gpio_4a216c40 - Initialized in 409.1 ms 2023-06-13 07:23:42,629 - INFO - mycodo.outputs.on_off_wireless_rpi_rf_5318ad16 - Initialized in 1362.8 ms 2023-06-13 07:23:42,869 - INFO - mycodo.outputs.on_off_wireless_rpi_rf_0246af63 - Initialized in 237.0 ms 2023-06-13 07:23:43,040 - INFO - mycodo.outputs.on_off_wireless_rpi_rf_3f6e3c73 - Initialized in 169.1 ms 2023-06-13 07:23:43,340 - INFO - mycodo.outputs.on_off_gpio_ceb7418b - Output setup on pin 12 and turned OFF (ON=HIGH) 2023-06-13 07:23:43,340 - INFO - mycodo.outputs.on_off_gpio_ceb7418b - Initialized in 298.3 ms 2023-06-13 07:23:43,508 - INFO - mycodo.outputs.on_off_gpio_e4822e6a - Output setup on pin 22 and turned ON (ON=HIGH) 2023-06-13 07:23:43,508 - INFO - mycodo.outputs.on_off_gpio_e4822e6a - Initialized in 166.3 ms 2023-06-13 07:23:43,839 - INFO - mycodo.outputs.on_off_kasa_plugs_7ea0d727 - Starting asyncio RPC server... 2023-06-13 07:23:44,007 - INFO - mycodo.outputs.on_off_kasa_plugs_7ea0d727 - Initialized in 496.5 ms 2023-06-13 07:23:44,194 - INFO - mycodo.outputs.on_off_kasa_plugs_067fb7f3 - Starting asyncio RPC server... 2023-06-13 07:23:44,315 - INFO - mycodo.outputs.on_off_kasa_plugs_067fb7f3 - Initialized in 302.6 ms 2023-06-13 07:23:44,495 - INFO - mycodo.outputs.on_off_kasa_plugs_332f0a30 - Starting asyncio RPC server... 2023-06-13 07:23:44,637 - INFO - mycodo.outputs.on_off_kasa_plugs_332f0a30 - Initialized in 318.1 ms 2023-06-13 07:23:44,807 - INFO - mycodo.outputs.on_off_kasa_plugs_7be40a44 - Starting asyncio RPC server... 2023-06-13 07:23:44,937 - INFO - mycodo.outputs.on_off_kasa_plugs_7be40a44 - Initialized in 298.0 ms 2023-06-13 07:23:45,117 - INFO - mycodo.outputs.on_off_kasa_hs300_0_4_2_4c46969e - Starting asyncio RPC server... 2023-06-13 07:23:50,996 - INFO - mycodo.outputs.on_off_kasa_hs300_0_4_2_4c46969e - Initialized in 6056.5 ms 2023-06-13 07:23:53,577 - INFO - mycodo.outputs.on_off_shell_39437c56 - Initialized in 250.2 ms 2023-06-13 07:23:55,006 - INFO - mycodo.controllers.controller_output - Activated in 15227.9 ms 2023-06-13 07:23:55,685 - INFO - mycodo.controllers.controller_conditional_a0417b2a - Activated in 70.7 ms 2023-06-13 07:23:55,903 - INFO - mycodo.controllers.controller_conditional_90a2bfdd - Activated in 99.8 ms 2023-06-13 07:23:56,183 - INFO - mycodo.controllers.controller_conditional_45c4d3c5 - Activated in 134.7 ms 2023-06-13 07:23:56,561 - INFO - mycodo.controllers.controller_conditional_c180b54a - Activated in 182.9 ms 2023-06-13 07:23:57,147 - INFO - mycodo.controllers.controller_conditional_8cb60bed - Activated in 177.9 ms 2023-06-13 07:23:57,502 - INFO - mycodo.controllers.controller_conditional_31d0988f - Activated in 84.8 ms 2023-06-13 07:23:57,802 - INFO - mycodo.controllers.controller_conditional_7afb1b88 - Activated in 136.0 ms 2023-06-13 07:23:57,803 - INFO - mycodo - All activated Conditional controllers started 2023-06-13 07:23:58,265 - INFO - mycodo.controllers.controller_trigger_092b8380 - Activated in 180.8 ms 2023-06-13 07:23:58,485 - INFO - mycodo.controllers.controller_trigger_6fdac2b6 - Activated in 93.2 ms 2023-06-13 07:23:58,712 - INFO - mycodo.controllers.controller_trigger_49d6c108 - Activated in 127.2 ms 2023-06-13 07:23:59,003 - INFO - mycodo.controllers.controller_trigger_5c72de1e - Activated in 73.5 ms 2023-06-13 07:23:59,175 - INFO - mycodo.controllers.controller_trigger_7a18fa7b - Activated in 69.8 ms 2023-06-13 07:23:59,346 - INFO - mycodo.controllers.controller_trigger_1d11f1a1 - Activated in 68.6 ms 2023-06-13 07:23:59,513 - INFO - mycodo.controllers.controller_trigger_e48f7e07 - Activated in 83.1 ms 2023-06-13 07:23:59,672 - INFO - mycodo.controllers.controller_trigger_9efb3322 - Activated in 72.7 ms 2023-06-13 07:24:00,208 - INFO - mycodo.controllers.controller_trigger_a3825040 - Activated in 131.2 ms 2023-06-13 07:24:00,453 - INFO - mycodo.controllers.controller_trigger_284bb790 - Activated in 80.8 ms 2023-06-13 07:24:00,628 - INFO - mycodo.controllers.controller_trigger_4bb4cc1e - Activated in 64.7 ms 2023-06-13 07:24:00,801 - INFO - mycodo.controllers.controller_trigger_ddb8d1c8 - Activated in 87.6 ms 2023-06-13 07:24:00,973 - INFO - mycodo.controllers.controller_trigger_b0eda3a4 - Activated in 88.3 ms 2023-06-13 07:24:01,264 - INFO - mycodo.controllers.controller_trigger_93bffa38 - Activated in 163.7 ms 2023-06-13 07:24:01,268 - INFO - mycodo - All activated Trigger controllers started 2023-06-13 07:24:01,857 - ERROR - mycodo.inputs.rpi_cpu_gpu_temperature_9ec8173c - Option 'path_temperature_cpu' required but was not found to be set by the user. Setting to default (/sys/class/thermal/thermal_zone0/temp). 2023-06-13 07:24:01,863 - ERROR - mycodo.inputs.rpi_cpu_gpu_temperature_9ec8173c - Option 'path_temperature_gpu' required but was not found to be set by the user. Setting to default (/usr/bin/vcgencmd). 2023-06-13 07:24:01,872 - INFO - mycodo.controllers.controller_input_9ec8173c - Activated in 375.6 ms 2023-06-13 07:24:03,701 - INFO - mycodo.controllers.controller_input_893af301 - Activated in 1517.8 ms 2023-06-13 07:24:04,191 - INFO - mycodo.controllers.controller_input_d481115f - Activated in 338.5 ms 2023-06-13 07:24:05,202 - INFO - mycodo.controllers.controller_input_d7f4d84e - Activated in 848.9 ms 2023-06-13 07:24:06,095 - INFO - mycodo.controllers.controller_input_9c2407ce - Activated in 788.2 ms 2023-06-13 07:24:08,288 - INFO - mycodo.controllers.controller_input_50b2f163 - Activated in 2032.7 ms 2023-06-13 07:24:08,350 - INFO - mycodo.inputs.mqtt_paho_50b2f163 - Connected to 192.168.3.39 as client_tGJz5bx0 2023-06-13 07:24:10,388 - INFO - mycodo.controllers.controller_input_ef2eb196 - Activated in 1406.5 ms 2023-06-13 07:24:10,394 - INFO - mycodo.inputs.mqtt_paho_ef2eb196 - Connected to 192.168.3.39 as client_mHgn0zgD 2023-06-13 07:31:25,425 - INFO - mycodo.controllers.controller_input_fc05a536 - Activated in 5952.0 ms 2023-06-13 07:31:26,997 - INFO - mycodo.controllers.controller_input_0f2a2b1a - Activated in 1371.9 ms 2023-06-13 07:31:30,244 - INFO - mycodo.controllers.controller_input_4ee54732 - Activated in 2931.6 ms 2023-06-13 07:31:30,244 - INFO - mycodo - All activated Input controllers started 2023-06-13 07:31:30,249 - INFO - mycodo - All activated PID controllers started 2023-06-13 07:31:31,003 - INFO - mycodo.function.bang_bang_3397e924 - Bang-Bang controller started with options: Measurement Device: 6c261530-3ac8-4482-8800-8035cecf95cb, Measurement: d3460c2b-df14-4c72-b854-e4944ca156d9, Output: 4c46969e-de6d-4747-a582-738cea12d651, Output_Channel: 3, Setpoint: 0.9, Hysteresis: 0.03, Direction: lower, Period: 5.0 2023-06-13 07:31:31,014 - INFO - mycodo.controllers.controller_function_3397e924 - Activated in 465.9 ms 2023-06-13 07:31:31,350 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:31:31,551 - INFO - mycodo.controllers.controller_function_6c261530 - Activated in 331.1 ms 2023-06-13 07:31:31,551 - INFO - mycodo - All activated Function controllers started 2023-06-13 07:31:35,421 - INFO - mycodo.controllers.controller_widget - Activated in 3855.0 ms 2023-06-13 07:31:36,423 - INFO - mycodo - Mycodo daemon started in 47.941 seconds

kizniche commented 1 year ago

What leads you to believe this is a Mycodo issue?

LucidEye commented 1 year ago

What leads you to believe this is a Mycodo issue?

I'm not saying it is specifically a Mycodo bug.
Seems like it might be an Influx issue from some of the errors I've been seeing. I have also tried changing the power supply and transferring my settings to a different SD card to make sure it's not a power or data corruption issue.... waiting to see what happens next. But I just don't see what error is starting this chain reaction that leads to the database locking up. The only errors I can see is that one or another of the inputs stops receiving measurements and then all sorts of faults start happening, then the database gets locked, and then I need to power-cycle the Pi to get it functioning again. There's just nothing in the logs that hint at WHY those inputs stop getting readings.... which makes me want to think hardware layer issues.... but I've tripple checked everything... I haven't made any electrical changes to the system since the last time I ran it except for adding that i2c IR leaf thermometer. The only big change was upgrading to a 64-bit OS and InfluxDB V2. Any ideas? I'm stumped :-(

kizniche commented 1 year ago

Have you determined what process(es) are causing the increasing CPU load?

LucidEye commented 1 year ago

No, I can't even get into the log file.
Attempting to open enough backlog lines of the log file in the web gui causes the web gui to crash. Any text editor I use to try to view the log file directly throws an error that there is a problem with the character encoding??? And once the database gets locked, the system becomes unresponsive, so I can't view the Mycodo web GUI for info, and I can't even SSH in and run htop or anything like that. :-( By the way, the whole system just crashed again, so it's not a power supply or SD card issue.

I can not make any sense of these errors because I can not search the file far back enough to see what caused this cascade in the first place... If you have any ideas from the log samples I have posted, can you please point me in the right direction to at least start looking for what might be causing this? This is my live system, and I am in the middle of a grow, and this system is also running the HVAC in the living space as well... so I can't just start shutting inputs and functions down and leaving them off for a day or more waiting for it to crash or not to see what is causing this.... it really all needs to be up and running 24/7.

Traceback (most recent call last): File "/var/mycodo-root/mycodo/databases/utils.py", line 26, in session_scope yield session File "/var/mycodo-root/mycodo/utils/database.py", line 70, in db_retrieve_table_daemon return_table = return_table.first() File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/query.py", line 2752, in first return self.limit(1)._iter().first() # type: ignore File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/query.py", line 2855, in _iter result: Union[ScalarResult[_T], Result[_T]] = self.session.execute( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/session.py", line 2229, in execute return self._execute_internal( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/session.py", line 2124, in _execute_internal result: Result[Any] = compile_state_cls.orm_execute_statement( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/context.py", line 253, in orm_execute_statement result = conn.execute( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1414, in execute return meth( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/sql/elements.py", line 486, in _execute_on_connection return connection._execute_clauseelement( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1638, in _execute_clauseelement ret = self._execute_context( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1842, in _execute_context return self._exec_single_context( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1983, in _exec_single_context self._handle_dbapi_exception( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 2326, in _handle_dbapi_exception raise sqlalchemy_exception.with_traceback(exc_info[2]) from e File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1964, in _exec_single_context self.dialect.do_execute( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/default.py", line 748, in do_execute cursor.execute(statement, parameters) sqlalchemy.exc.OperationalError: (sqlite3.OperationalError) database is locked [SQL: SELECT conditional.id AS conditional_id, conditional.unique_id AS conditional_unique_id, conditional.name AS conditional_name, conditional.position_y AS conditional_position_y, conditional.is_activated AS conditional_is_activated, conditional.log_level_debug AS conditional_log_level_debug, conditional.conditional_statement AS conditional_conditional_statement, conditional.conditional_import AS conditional_conditional_import, conditional.conditional_initialize AS conditional_conditional_initialize, conditional.conditional_status AS conditional_conditional_status, conditional.period AS conditional_period, conditional.start_offset AS conditional_start_offset, conditional.pyro_timeout AS conditional_pyro_timeout, conditional.use_pylint AS conditional_use_pylint, conditional.message_include_code AS conditional_message_include_code, conditional.custom_options AS conditional_custom_options FROM conditional WHERE conditional.unique_id = ? LIMIT ? OFFSET ?] [parameters: ('7afb1b88-ca9d-479f-bc9f-8b6fcc0482e3', 1, 0)] (Background on this error at: https://sqlalche.me/e/20/e3q8) 2023-06-13 07:00:55,884 - ERROR - mycodo.controllers.controller_input_4ee54732 - loop() Error Traceback (most recent call last): File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1964, in _exec_single_context self.dialect.do_execute( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/default.py", line 748, in do_execute cursor.execute(statement, parameters) sqlite3.OperationalError: database is locked

The above exception was the direct cause of the following exception:

Traceback (most recent call last): File "/var/mycodo-root/mycodo/controllers/base_controller.py", line 81, in run self.loop() File "/var/mycodo-root/mycodo/controllers/controller_input.py", line 220, in loop measurements_dict = self.create_measurements_dict() File "/var/mycodo-root/mycodo/controllers/controller_input.py", line 418, in create_measurements_dict measurement = self.device_measurements.filter( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/query.py", line 2752, in first return self.limit(1)._iter().first() # type: ignore File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/query.py", line 2855, in _iter result: Union[ScalarResult[_T], Result[_T]] = self.session.execute( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/session.py", line 2229, in execute return self._execute_internal( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/session.py", line 2124, in _execute_internal result: Result[Any] = compile_state_cls.orm_execute_statement( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/context.py", line 253, in orm_execute_statement result = conn.execute( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1414, in execute return meth( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/sql/elements.py", line 486, in _execute_on_connection return connection._execute_clauseelement( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1638, in _execute_clauseelement ret = self._execute_context( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1842, in _execute_context return self._exec_single_context( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1983, in _exec_single_context self._handle_dbapi_exception( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 2326, in _handle_dbapi_exception raise sqlalchemy_exception.with_traceback(exc_info[2]) from e File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1964, in _exec_single_context self.dialect.do_execute( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/default.py", line 748, in do_execute cursor.execute(statement, parameters) sqlalchemy.exc.OperationalError: (sqlite3.OperationalError) database is locked [SQL: SELECT device_measurements.id AS device_measurements_id, device_measurements.unique_id AS device_measurements_unique_id, device_measurements.name AS device_measurements_name, device_measurements.device_type AS device_measurements_device_type, device_measurements.device_id AS device_measurements_device_id, device_measurements.is_enabled AS device_measurements_is_enabled, device_measurements.measurement AS device_measurements_measurement, device_measurements.measurement_type AS device_measurements_measurement_type, device_measurements.unit AS device_measurements_unit, device_measurements.channel AS device_measurements_channel, device_measurements.rescale_method AS device_measurements_rescale_method, device_measurements.rescale_equation AS device_measurements_rescale_equation, device_measurements.invert_scale AS device_measurements_invert_scale, device_measurements.rescaled_measurement AS device_measurements_rescaled_measurement, device_measurements.rescaled_unit AS device_measurements_rescaled_unit, device_measurements.scale_from_min AS device_measurements_scale_from_min, device_measurements.scale_from_max AS device_measurements_scale_from_max, device_measurements.scale_to_min AS device_measurements_scale_to_min, device_measurements.scale_to_max AS device_measurements_scale_to_max, device_measurements.conversion_id AS device_measurements_conversion_id FROM device_measurements WHERE device_measurements.device_id = ? AND device_measurements.channel = ? LIMIT ? OFFSET ?] [parameters: ('4ee54732-e22d-4e2b-8fd4-e77535112b9e', 0, 1, 0)] (Background on this error at: https://sqlalche.me/e/20/e3q8) 2023-06-13 07:00:56,809 - ERROR - mycodo.database - The Mycodo database is locked. Trying to access again in 1 second... 2023-06-13 07:00:56,820 - ERROR - mycodo.database - The Mycodo database is locked. Trying to access again in 1 second... 2023-06-13 07:00:56,850 - ERROR - mycodo.controllers.controller_conditional_a0417b2a - Exception executing Run Python Code Traceback (most recent call last): File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1964, in _exec_single_context self.dialect.do_execute( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/default.py", line 748, in do_execute cursor.execute(statement, parameters) sqlite3.OperationalError: database is locked

The above exception was the direct cause of the following exception:

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/pi/Mycodo/mycodo/user_python_code/conditional_a0417b2a-805d-4858-90b7-7e3f5151df7e.py", line 46, in conditional_code_run self.run_action("cba8014f", value={"payload": "0,0,0"}) File "/var/mycodo-root/mycodo/controllers/base_conditional.py", line 46, in run_action action = new_session.query(Actions).filter( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/query.py", line 2752, in first return self.limit(1)._iter().first() # type: ignore File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/query.py", line 2855, in _iter result: Union[ScalarResult[_T], Result[_T]] = self.session.execute( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/session.py", line 2229, in execute return self._execute_internal( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/session.py", line 2124, in _execute_internal result: Result[Any] = compile_state_cls.orm_execute_statement( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/context.py", line 253, in orm_execute_statement result = conn.execute( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1414, in execute return meth( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/sql/elements.py", line 486, in _execute_on_connection return connection._execute_clauseelement( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1638, in _execute_clauseelement ret = self._execute_context( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1842, in _execute_context return self._exec_single_context( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1983, in _exec_single_context self._handle_dbapi_exception( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 2326, in _handle_dbapi_exception raise sqlalchemy_exception.with_traceback(exc_info[2]) from e File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1964, in _exec_single_context self.dialect.do_execute( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/default.py", line 748, in do_execute cursor.execute(statement, parameters) sqlalchemy.exc.OperationalError: (sqlite3.OperationalError) database is locked [SQL: SELECT function_actions.id AS function_actions_id, function_actions.unique_id AS function_actions_unique_id, function_actions.function_id AS function_actions_function_id, function_actions.function_type AS function_actions_function_type, function_actions.action_type AS function_actions_action_type, function_actions.custom_options AS function_actions_custom_options, function_actions.pause_duration AS function_actions_pause_duration, function_actions.do_unique_id AS function_actions_do_unique_id, function_actions.do_action_string AS function_actions_do_action_string, function_actions.do_output_state AS function_actions_do_output_state, function_actions.do_output_amount AS function_actions_do_output_amount, function_actions.do_output_duration AS function_actions_do_output_duration, function_actions.do_output_pwm AS function_actions_do_output_pwm, function_actions.do_output_pwm2 AS function_actions_do_output_pwm2, function_actions.do_camera_duration AS function_actions_do_camera_duration, function_actions.remote AS function_actions_remote, function_actions.code AS function_actions_code, function_actions.send_times AS function_actions_send_times FROM function_actions WHERE (function_actions.unique_id LIKE ? || '%') LIMIT ? OFFSET ?] [parameters: ('cba8014f', 1, 0)] (Background on this error at: https://sqlalche.me/e/20/e3q8) 2023-06-13 07:00:56,864 - ERROR - mycodo - Daemon Error Traceback (most recent call last): File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1964, in _exec_single_context self.dialect.do_execute( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/default.py", line 748, in do_execute cursor.execute(statement, parameters) sqlite3.OperationalError: database is locked

The above exception was the direct cause of the following exception:

Traceback (most recent call last): File "/var/mycodo-root/mycodo/mycodo_daemon.py", line 163, in run self.check_all_timelapses(now) File "/var/mycodo-root/mycodo/mycodo_daemon.py", line 1023, in check_all_timelapses for each_camera in new_session.query(Camera).all(): File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/query.py", line 2697, in all return self._iter().all() # type: ignore File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/query.py", line 2855, in _iter result: Union[ScalarResult[_T], Result[_T]] = self.session.execute( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/session.py", line 2229, in execute return self._execute_internal( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/session.py", line 2124, in _execute_internal result: Result[Any] = compile_state_cls.orm_execute_statement( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/context.py", line 253, in orm_execute_statement result = conn.execute( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1414, in execute return meth( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/sql/elements.py", line 486, in _execute_on_connection return connection._execute_clauseelement( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1638, in _execute_clauseelement ret = self._execute_context( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1842, in _execute_context return self._exec_single_context( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1983, in _exec_single_context self._handle_dbapi_exception( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 2326, in _handle_dbapi_exception raise sqlalchemy_exception.with_traceback(exc_info[2]) from e File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1964, in _exec_single_context self.dialect.do_execute( File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/default.py", line 748, in do_execute cursor.execute(statement, parameters) sqlalchemy.exc.OperationalError: (sqlite3.OperationalError) database is locked [SQL: SELECT camera.id AS camera_id, camera.unique_id AS camera_unique_id, camera.name AS camera_name, camera.library AS camera_library, camera.device AS camera_device, camera.opencv_device AS camera_opencv_device, camera.hflip AS camera_hflip, camera.vflip AS camera_vflip, camera.rotation AS camera_rotation, camera.brightness AS camera_brightness, camera.contrast AS camera_contrast, camera.exposure AS camera_exposure, camera.gain AS camera_gain, camera.hue AS camera_hue, camera.saturation AS camera_saturation, camera.white_balance AS camera_white_balance, camera.custom_options AS camera_custom_options, camera.output_id AS camera_output_id, camera.output_duration AS camera_output_duration, camera.cmd_pre_camera AS camera_cmd_pre_camera, camera.cmd_post_camera AS camera_cmd_post_camera, camera.stream_started AS camera_stream_started, camera.hide_still AS camera_hide_still, camera.hide_timelapse AS camera_hide_timelapse, camera.url_still AS camera_url_still, camera.url_stream AS camera_url_stream, camera.json_headers AS camera_json_headers, camera.show_preview AS camera_show_preview, camera.output_format AS camera_output_format, camera.timelapse_started AS camera_timelapse_started, camera.timelapse_paused AS camera_timelapse_paused, camera.timelapse_start_time AS camera_timelapse_start_time, camera.timelapse_end_time AS camera_timelapse_end_time, camera.timelapse_interval AS camera_timelapse_interval, camera.timelapse_next_capture AS camera_timelapse_next_capture, camera.timelapse_capture_number AS camera_timelapse_capture_number, camera.timelapse_last_file AS camera_timelapse_last_file, camera.timelapse_last_ts AS camera_timelapse_last_ts, camera.still_last_file AS camera_still_last_file, camera.still_last_ts AS camera_still_last_ts, camera.path_still AS camera_path_still, camera.path_timelapse AS camera_path_timelapse, camera.path_video AS camera_path_video, camera.width AS camera_width, camera.height AS camera_height, camera.resolution_stream_width AS camera_resolution_stream_width, camera.resolution_stream_height AS camera_resolution_stream_height, camera.stream_fps AS camera_stream_fps, camera.picamera_shutter_speed AS camera_picamera_shutter_speed, camera.picamera_sharpness AS camera_picamera_sharpness, camera.picamera_iso AS camera_picamera_iso, camera.picamera_awb AS camera_picamera_awb, camera.picamera_awb_gain_red AS camera_picamera_awb_gain_red, camera.picamera_awb_gain_blue AS camera_picamera_awb_gain_blue, camera.picamera_exposure_mode AS camera_picamera_exposure_mode, camera.picamera_meter_mode AS camera_picamera_meter_mode, camera.picamera_image_effect AS camera_picamera_image_effect FROM camera] (Background on this error at: https://sqlalche.me/e/20/e3q8) 2023-06-13 07:00:56,865 - ERROR - mycodo.database - The Mycodo database is locked. Trying to access again in 1 second... 2023-06-13 07:00:56,869 - ERROR - mycodo.database - The Mycodo database is locked. Trying to access again in 1 second... 2023-06-13 07:00:56,872 - ERROR - mycodo.database - The Mycodo database is locked. Trying to access again in 1 second... 2023-06-13 07:00:56,896 - ERROR - mycodo.database - The Mycodo database is locked. Trying to access again in 1 second... 2023-06-13 07:00:57,399 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:00:58,756 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:01:03,653 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:01:08,264 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:01:13,288 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:01:18,290 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:01:46,138 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:01:48,397 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:01:53,208 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:02:16,649 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:02:18,538 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:02:23,318 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:02:53,712 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:02:58,478 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:03:03,338 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:03:08,311 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:03:38,002 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:03:38,489 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:03:43,358 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:03:48,418 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:03:54,602 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:03:59,195 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:04:03,320 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:06:08,303 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:06:13,328 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:06:18,634 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:06:29,632 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:06:33,318 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:06:38,393 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:10:19,296 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:10:23,447 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:10:28,271 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:10:58,077 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:10:58,691 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:11:03,625 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:11:08,253 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:11:21,168 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:11:23,518 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:11:28,301 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:11:33,383 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:11:38,961 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:12:04,066 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:12:09,021 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:12:13,411 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:12:18,278 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:12:23,586 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:12:28,314 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:12:33,360 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:12:38,442 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:12:43,228 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:12:48,277 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:12:55,575 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:15:33,355 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:15:38,421 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:15:43,195 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:15:48,309 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:15:53,312 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:15:58,222 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:16:03,273 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:16:08,405 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:16:13,413 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:16:18,199 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:16:23,287 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:16:28,291 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:16:33,300 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:16:38,316 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:17:06,306 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:17:08,375 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:17:21,748 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:17:23,274 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:17:28,435 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:17:33,283 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:17:38,367 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:17:43,458 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:18:15,988 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:18:18,296 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:18:23,401 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:18:39,833 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:18:43,397 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:18:48,206 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:18:53,206 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:19:23,910 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:19:38,172 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:19:38,788 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:19:43,390 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:19:49,772 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:19:53,352 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:19:58,535 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:20:27,817 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:20:28,387 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:20:33,424 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:20:38,345 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:20:50,356 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:20:54,743 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:20:58,467 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:21:03,353 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:21:32,293 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:21:33,297 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:21:38,305 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:21:51,345 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:21:53,349 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:28:49,937 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:28:53,243 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:28:58,316 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:29:03,420 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:29:08,258 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:29:13,366 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:29:18,424 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:23:39,576 - INFO - mycodo - Mycodo daemon v8.15.8 starting 2023-06-13 07:23:39,596 - INFO - mycodo.pyro_daemon - Starting Pyro5 daemon 2023-06-13 07:23:40,300 - INFO - mycodo.outputs.on_off_gpio_cfaaccb0 - Output setup on pin 20 and turned OFF (ON=HIGH) 2023-06-13 07:23:40,301 - INFO - mycodo.outputs.on_off_gpio_cfaaccb0 - Initialized in 219.0 ms 2023-06-13 07:23:40,532 - INFO - mycodo.outputs.pwm_gpio_c0598a74 - Output setup on Any pin 18 at 22000 Hertz 2023-06-13 07:23:40,534 - INFO - mycodo.outputs.pwm_gpio_c0598a74 - PWM set to 30.0 % duty cycle (user-specified value) 2023-06-13 07:23:40,535 - INFO - mycodo.outputs.pwm_gpio_c0598a74 - Initialized in 232.6 ms 2023-06-13 07:23:40,851 - INFO - mycodo.outputs.on_off_gpio_d30253e9 - Output setup on pin 16 and turned OFF (ON=HIGH) 2023-06-13 07:23:40,853 - INFO - mycodo.outputs.on_off_gpio_d30253e9 - Initialized in 313.1 ms 2023-06-13 07:23:41,263 - INFO - mycodo.outputs.on_off_gpio_4a216c40 - Output setup on pin 21 and turned OFF (ON=HIGH) 2023-06-13 07:23:41,264 - INFO - mycodo.outputs.on_off_gpio_4a216c40 - Initialized in 409.1 ms 2023-06-13 07:23:42,629 - INFO - mycodo.outputs.on_off_wireless_rpi_rf_5318ad16 - Initialized in 1362.8 ms 2023-06-13 07:23:42,869 - INFO - mycodo.outputs.on_off_wireless_rpi_rf_0246af63 - Initialized in 237.0 ms 2023-06-13 07:23:43,040 - INFO - mycodo.outputs.on_off_wireless_rpi_rf_3f6e3c73 - Initialized in 169.1 ms 2023-06-13 07:23:43,340 - INFO - mycodo.outputs.on_off_gpio_ceb7418b - Output setup on pin 12 and turned OFF (ON=HIGH) 2023-06-13 07:23:43,340 - INFO - mycodo.outputs.on_off_gpio_ceb7418b - Initialized in 298.3 ms 2023-06-13 07:23:43,508 - INFO - mycodo.outputs.on_off_gpio_e4822e6a - Output setup on pin 22 and turned ON (ON=HIGH) 2023-06-13 07:23:43,508 - INFO - mycodo.outputs.on_off_gpio_e4822e6a - Initialized in 166.3 ms 2023-06-13 07:23:43,839 - INFO - mycodo.outputs.on_off_kasa_plugs_7ea0d727 - Starting asyncio RPC server... 2023-06-13 07:23:44,007 - INFO - mycodo.outputs.on_off_kasa_plugs_7ea0d727 - Initialized in 496.5 ms 2023-06-13 07:23:44,194 - INFO - mycodo.outputs.on_off_kasa_plugs_067fb7f3 - Starting asyncio RPC server... 2023-06-13 07:23:44,315 - INFO - mycodo.outputs.on_off_kasa_plugs_067fb7f3 - Initialized in 302.6 ms 2023-06-13 07:23:44,495 - INFO - mycodo.outputs.on_off_kasa_plugs_332f0a30 - Starting asyncio RPC server... 2023-06-13 07:23:44,637 - INFO - mycodo.outputs.on_off_kasa_plugs_332f0a30 - Initialized in 318.1 ms 2023-06-13 07:23:44,807 - INFO - mycodo.outputs.on_off_kasa_plugs_7be40a44 - Starting asyncio RPC server... 2023-06-13 07:23:44,937 - INFO - mycodo.outputs.on_off_kasa_plugs_7be40a44 - Initialized in 298.0 ms 2023-06-13 07:23:45,117 - INFO - mycodo.outputs.on_off_kasa_hs300_0_4_2_4c46969e - Starting asyncio RPC server... 2023-06-13 07:23:50,996 - INFO - mycodo.outputs.on_off_kasa_hs300_0_4_2_4c46969e - Initialized in 6056.5 ms 2023-06-13 07:23:53,577 - INFO - mycodo.outputs.on_off_shell_39437c56 - Initialized in 250.2 ms 2023-06-13 07:23:55,006 - INFO - mycodo.controllers.controller_output - Activated in 15227.9 ms 2023-06-13 07:23:55,685 - INFO - mycodo.controllers.controller_conditional_a0417b2a - Activated in 70.7 ms 2023-06-13 07:23:55,903 - INFO - mycodo.controllers.controller_conditional_90a2bfdd - Activated in 99.8 ms 2023-06-13 07:23:56,183 - INFO - mycodo.controllers.controller_conditional_45c4d3c5 - Activated in 134.7 ms 2023-06-13 07:23:56,561 - INFO - mycodo.controllers.controller_conditional_c180b54a - Activated in 182.9 ms 2023-06-13 07:23:57,147 - INFO - mycodo.controllers.controller_conditional_8cb60bed - Activated in 177.9 ms 2023-06-13 07:23:57,502 - INFO - mycodo.controllers.controller_conditional_31d0988f - Activated in 84.8 ms 2023-06-13 07:23:57,802 - INFO - mycodo.controllers.controller_conditional_7afb1b88 - Activated in 136.0 ms 2023-06-13 07:23:57,803 - INFO - mycodo - All activated Conditional controllers started 2023-06-13 07:23:58,265 - INFO - mycodo.controllers.controller_trigger_092b8380 - Activated in 180.8 ms 2023-06-13 07:23:58,485 - INFO - mycodo.controllers.controller_trigger_6fdac2b6 - Activated in 93.2 ms 2023-06-13 07:23:58,712 - INFO - mycodo.controllers.controller_trigger_49d6c108 - Activated in 127.2 ms 2023-06-13 07:23:59,003 - INFO - mycodo.controllers.controller_trigger_5c72de1e - Activated in 73.5 ms 2023-06-13 07:23:59,175 - INFO - mycodo.controllers.controller_trigger_7a18fa7b - Activated in 69.8 ms 2023-06-13 07:23:59,346 - INFO - mycodo.controllers.controller_trigger_1d11f1a1 - Activated in 68.6 ms 2023-06-13 07:23:59,513 - INFO - mycodo.controllers.controller_trigger_e48f7e07 - Activated in 83.1 ms 2023-06-13 07:23:59,672 - INFO - mycodo.controllers.controller_trigger_9efb3322 - Activated in 72.7 ms 2023-06-13 07:24:00,208 - INFO - mycodo.controllers.controller_trigger_a3825040 - Activated in 131.2 ms 2023-06-13 07:24:00,453 - INFO - mycodo.controllers.controller_trigger_284bb790 - Activated in 80.8 ms 2023-06-13 07:24:00,628 - INFO - mycodo.controllers.controller_trigger_4bb4cc1e - Activated in 64.7 ms 2023-06-13 07:24:00,801 - INFO - mycodo.controllers.controller_trigger_ddb8d1c8 - Activated in 87.6 ms 2023-06-13 07:24:00,973 - INFO - mycodo.controllers.controller_trigger_b0eda3a4 - Activated in 88.3 ms 2023-06-13 07:24:01,264 - INFO - mycodo.controllers.controller_trigger_93bffa38 - Activated in 163.7 ms 2023-06-13 07:24:01,268 - INFO - mycodo - All activated Trigger controllers started 2023-06-13 07:24:01,857 - ERROR - mycodo.inputs.rpi_cpu_gpu_temperature_9ec8173c - Option 'path_temperature_cpu' required but was not found to be set by the user. Setting to default (/sys/class/thermal/thermal_zone0/temp). 2023-06-13 07:24:01,863 - ERROR - mycodo.inputs.rpi_cpu_gpu_temperature_9ec8173c - Option 'path_temperature_gpu' required but was not found to be set by the user. Setting to default (/usr/bin/vcgencmd). 2023-06-13 07:24:01,872 - INFO - mycodo.controllers.controller_input_9ec8173c - Activated in 375.6 ms 2023-06-13 07:24:03,701 - INFO - mycodo.controllers.controller_input_893af301 - Activated in 1517.8 ms 2023-06-13 07:24:04,191 - INFO - mycodo.controllers.controller_input_d481115f - Activated in 338.5 ms 2023-06-13 07:24:05,202 - INFO - mycodo.controllers.controller_input_d7f4d84e - Activated in 848.9 ms 2023-06-13 07:24:06,095 - INFO - mycodo.controllers.controller_input_9c2407ce - Activated in 788.2 ms 2023-06-13 07:24:08,288 - INFO - mycodo.controllers.controller_input_50b2f163 - Activated in 2032.7 ms 2023-06-13 07:24:08,350 - INFO - mycodo.inputs.mqtt_paho_50b2f163 - Connected to 192.168.3.39 as client_tGJz5bx0 2023-06-13 07:24:10,388 - INFO - mycodo.controllers.controller_input_ef2eb196 - Activated in 1406.5 ms 2023-06-13 07:24:10,394 - INFO - mycodo.inputs.mqtt_paho_ef2eb196 - Connected to 192.168.3.39 as client_mHgn0zgD 2023-06-13 07:31:25,425 - INFO - mycodo.controllers.controller_input_fc05a536 - Activated in 5952.0 ms 2023-06-13 07:31:26,997 - INFO - mycodo.controllers.controller_input_0f2a2b1a - Activated in 1371.9 ms 2023-06-13 07:31:30,244 - INFO - mycodo.controllers.controller_input_4ee54732 - Activated in 2931.6 ms 2023-06-13 07:31:30,244 - INFO - mycodo - All activated Input controllers started 2023-06-13 07:31:30,249 - INFO - mycodo - All activated PID controllers started 2023-06-13 07:31:31,003 - INFO - mycodo.function.bang_bang_3397e924 - Bang-Bang controller started with options: Measurement Device: 6c261530-3ac8-4482-8800-8035cecf95cb, Measurement: d3460c2b-df14-4c72-b854-e4944ca156d9, Output: 4c46969e-de6d-4747-a582-738cea12d651, Output_Channel: 3, Setpoint: 0.9, Hysteresis: 0.03, Direction: lower, Period: 5.0 2023-06-13 07:31:31,014 - INFO - mycodo.controllers.controller_function_3397e924 - Activated in 465.9 ms 2023-06-13 07:31:31,350 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-13 07:31:31,551 - INFO - mycodo.controllers.controller_function_6c261530 - Activated in 331.1 ms 2023-06-13 07:31:31,551 - INFO - mycodo - All activated Function controllers started 2023-06-13 07:31:35,421 - INFO - mycodo.controllers.controller_widget - Activated in 3855.0 ms 2023-06-13 07:31:36,423 - INFO - mycodo - Mycodo daemon started in 47.941 seconds 2023-06-13 08:24:16,175 - ERROR - mycodo.controllers.controller_function_3397e924 - Exception while running loop() Traceback (most recent call last): File "/var/mycodo-root/env/lib/python3.9/site-packages/urllib3/connection.py", line 174, in _new_conn conn = connection.create_connection( File "/var/mycodo-root/env/lib/python3.9/site-packages/urllib3/util/connection.py", line 95, in create_connection raise err File "/var/mycodo-root/env/lib/python3.9/site-packages/urllib3/util/connection.py", line 85, in create_connection sock.connect(sa) ConnectionRefusedError: [Errno 111] Connection refused

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "/var/mycodo-root/mycodo/controllers/controller_function.py", line 79, in loop self.run_function.loop() File "/home/pi/Mycodo/mycodo/functions/bang_bang.py", line 173, in loop last_measurement = self.get_last_measurement( File "/var/mycodo-root/mycodo/abstract_base_controller.py", line 533, in get_last_measurement return get_last_measurement(device_id, measurement_id, max_age=max_age) File "/var/mycodo-root/mycodo/utils/influx.py", line 317, in get_last_measurement last_measurement = read_influxdb_single( File "/var/mycodo-root/mycodo/utils/influx.py", line 367, in read_influxdb_single data = query_string( File "/var/mycodo-root/mycodo/utils/influx.py", line 296, in query_string ret_value = query_flux( File "/var/mycodo-root/mycodo/utils/influx.py", line 281, in query_flux tables = client.query_api().query(query) File "/var/mycodo-root/env/lib/python3.9/site-packages/influxdb_client/client/query_api.py", line 203, in query response = self._query_api.post_query(org=org, query=self._create_query(query, self.default_dialect, params), File "/var/mycodo-root/env/lib/python3.9/site-packages/influxdb_client/service/query_service.py", line 279, in post_query (data) = self.post_query_with_http_info(kwargs) # noqa: E501 File "/var/mycodo-root/env/lib/python3.9/site-packages/influxdb_client/service/query_service.py", line 305, in post_query_with_http_info return self.api_client.call_api( File "/var/mycodo-root/env/lib/python3.9/site-packages/influxdb_client/_sync/api_client.py", line 343, in call_api return self.call_api(resource_path, method, File "/var/mycodo-root/env/lib/python3.9/site-packages/influxdb_client/_sync/api_client.py", line 121, in __call_api self._signin(resource_path=resource_path) File "/var/mycodo-root/env/lib/python3.9/site-packages/influxdb_client/_sync/api_client.py", line 657, in _signin http_info = SigninService(self).post_signin_with_http_info() File "/var/mycodo-root/env/lib/python3.9/site-packages/influxdb_client/service/signin_service.py", line 74, in post_signin_with_http_info return self.api_client.call_api( File "/var/mycodo-root/env/lib/python3.9/site-packages/influxdb_client/_sync/api_client.py", line 343, in call_api return self.call_api(resource_path, method, File "/var/mycodo-root/env/lib/python3.9/site-packages/influxdb_client/_sync/api_client.py", line 173, in __call_api response_data = self.request( File "/var/mycodo-root/env/lib/python3.9/site-packages/influxdb_client/_sync/api_client.py", line 388, in request return self.rest_client.POST(url, File "/var/mycodo-root/env/lib/python3.9/site-packages/influxdb_client/_sync/rest.py", line 311, in POST return self.request("POST", url, File "/var/mycodo-root/env/lib/python3.9/site-packages/influxdb_client/_sync/rest.py", line 186, in request r = self.pool_manager.request( File "/var/mycodo-root/env/lib/python3.9/site-packages/urllib3/request.py", line 78, in request return self.request_encode_body( File "/var/mycodo-root/env/lib/python3.9/site-packages/urllib3/request.py", line 170, in request_encode_body return self.urlopen(method, url, extra_kw) File "/var/mycodo-root/env/lib/python3.9/site-packages/urllib3/poolmanager.py", line 376, in urlopen response = conn.urlopen(method, u.request_uri, kw) File "/var/mycodo-root/env/lib/python3.9/site-packages/urllib3/connectionpool.py", line 787, in urlopen retries = retries.increment( File "/var/mycodo-root/env/lib/python3.9/site-packages/urllib3/util/retry.py", line 525, in increment raise six.reraise(type(error), error, _stacktrace) File "/var/mycodo-root/env/lib/python3.9/site-packages/urllib3/packages/six.py", line 770, in reraise raise value File "/var/mycodo-root/env/lib/python3.9/site-packages/urllib3/connectionpool.py", line 703, in urlopen httplib_response = self._make_request( File "/var/mycodo-root/env/lib/python3.9/site-packages/urllib3/connectionpool.py", line 398, in _make_request conn.request(method, url, httplib_request_kw) File "/var/mycodo-root/env/lib/python3.9/site-packages/urllib3/connection.py", line 244, in request super(HTTPConnection, self).request(method, url, body=body, headers=headers) File "/usr/lib/python3.9/http/client.py", line 1255, in request self._send_request(method, url, body, headers, encode_chunked) File "/usr/lib/python3.9/http/client.py", line 1301, in _send_request self.endheaders(body, encode_chunked=encode_chunked) File "/usr/lib/python3.9/http/client.py", line 1250, in endheaders self._send_output(message_body, encode_chunked=encode_chunked) File "/usr/lib/python3.9/http/client.py", line 1010, in _send_output self.send(msg) File "/usr/lib/python3.9/http/client.py", line 950, in send self.connect() File "/var/mycodo-root/env/lib/python3.9/site-packages/urllib3/connection.py", line 205, in connect conn = self._new_conn() File "/var/mycodo-root/env/lib/python3.9/site-packages/urllib3/connection.py", line 186, in _new_conn raise NewConnectionError( urllib3.exceptions.NewConnectionError: <urllib3.connection.HTTPConnection object at 0x7f244384c0>: Failed to establish a new connection: [Errno 111] Connection refused 2023-06-13 08:24:16,617 - ERROR - mycodo.controllers.controller_conditional_45c4d3c5 - 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/pi/Mycodo/mycodo/user_python_code/conditional_45c4d3c5-5fda-41c6-81ca-a67f84631936.py", line 24, in conditional_code_run measurement = self.condition("1c8c49f3") # Replace ID with correct Conditional ID File "/var/mycodo-root/mycodo/controllers/base_conditional.py", line 78, in condition return self.control.get_condition_measurement(full_cond_id) File "/var/mycodo-root/mycodo/mycodo_client.py", line 184, in get_condition_measurement return self.proxy().get_condition_measurement(condition_id) File "/var/mycodo-root/env/lib/python3.9/site-packages/Pyro5/client.py", line 510, in call return self.send(self.name, args, kwargs) File "/var/mycodo-root/env/lib/python3.9/site-packages/Pyro5/client.py", line 268, in _pyroInvoke data = serializer.loads(msg.data) File "/var/mycodo-root/env/lib/python3.9/site-packages/Pyro5/serializers.py", line 290, in loads return self.recreate_classes(serpent.loads(data)) File "/var/mycodo-root/env/lib/python3.9/site-packages/Pyro5/serializers.py", line 256, in recreate_classes return self.dict_to_class(literal) File "/var/mycodo-root/env/lib/python3.9/site-packages/Pyro5/serializers.py", line 309, in dict_to_class return super(SerpentSerializer, cls).dict_to_class(data) File "/var/mycodo-root/env/lib/python3.9/site-packages/Pyro5/serializers.py", line 235, in dict_to_class raise errors.SerializeError("unsupported serialized class: " + classname) Pyro5.errors.SerializeError: unsupported serialized class: urllib3.exceptions.NewConnectionError 2023-06-13 08:24:17,382 - ERROR - mycodo.controllers.controller_function_6c261530 - Exception while running loop() Traceback (most recent call last): File "/var/mycodo-root/env/lib/python3.9/site-packages/urllib3/connection.py", line 174, in _new_conn conn = connection.create_connection( File "/var/mycodo-root/env/lib/python3.9/site-packages/urllib3/util/connection.py", line 95, in create_connection raise err File "/var/mycodo-root/env/lib/python3.9/site-packages/urllib3/util/connection.py", line 85, in create_connection sock.connect(sa) ConnectionRefusedError: [Errno 111] Connection refused

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "/var/mycodo-root/mycodo/controllers/controller_function.py", line 79, in loop self.run_function.loop() File "/home/pi/Mycodo/mycodo/functions/vapor_pressure_deficit.py", line 166, in loop last_measurement_temp = self.get_last_measurement( File "/var/mycodo-root/mycodo/abstract_base_controller.py", line 533, in get_last_measurement return get_last_measurement(device_id, measurement_id, max_age=max_age) File "/var/mycodo-root/mycodo/utils/influx.py", line 317, in get_last_measurement last_measurement = read_influxdb_single( File "/var/mycodo-root/mycodo/utils/influx.py", line 367, in read_influxdb_single data = query_string( File "/var/mycodo-root/mycodo/utils/influx.py", line 296, in query_string ret_value = query_flux( File "/var/mycodo-root/mycodo/utils/influx.py", line 281, in query_flux tables = client.query_api().query(query) File "/var/mycodo-root/env/lib/python3.9/site-packages/influxdb_client/client/query_api.py", line 203, in query response = self._query_api.post_query(org=org, query=self._create_query(query, self.default_dialect, params), File "/var/mycodo-root/env/lib/python3.9/site-packages/influxdb_client/service/query_service.py", line 279, in post_query (data) = self.post_query_with_http_info(kwargs) # noqa: E501 File "/var/mycodo-root/env/lib/python3.9/site-packages/influxdb_client/service/query_service.py", line 305, in post_query_with_http_info return self.api_client.call_api( File "/var/mycodo-root/env/lib/python3.9/site-packages/influxdb_client/_sync/api_client.py", line 343, in call_api return self.call_api(resource_path, method, File "/var/mycodo-root/env/lib/python3.9/site-packages/influxdb_client/_sync/api_client.py", line 121, in __call_api self._signin(resource_path=resource_path) File "/var/mycodo-root/env/lib/python3.9/site-packages/influxdb_client/_sync/api_client.py", line 657, in _signin http_info = SigninService(self).post_signin_with_http_info() File "/var/mycodo-root/env/lib/python3.9/site-packages/influxdb_client/service/signin_service.py", line 74, in post_signin_with_http_info return self.api_client.call_api( File "/var/mycodo-root/env/lib/python3.9/site-packages/influxdb_client/_sync/api_client.py", line 343, in call_api return self.call_api(resource_path, method, File "/var/mycodo-root/env/lib/python3.9/site-packages/influxdb_client/_sync/api_client.py", line 173, in __call_api response_data = self.request( File "/var/mycodo-root/env/lib/python3.9/site-packages/influxdb_client/_sync/api_client.py", line 388, in request return self.rest_client.POST(url, File "/var/mycodo-root/env/lib/python3.9/site-packages/influxdb_client/_sync/rest.py", line 311, in POST return self.request("POST", url, File "/var/mycodo-root/env/lib/python3.9/site-packages/influxdb_client/_sync/rest.py", line 186, in request r = self.pool_manager.request( File "/var/mycodo-root/env/lib/python3.9/site-packages/urllib3/request.py", line 78, in request return self.request_encode_body( File "/var/mycodo-root/env/lib/python3.9/site-packages/urllib3/request.py", line 170, in request_encode_body return self.urlopen(method, url, extra_kw) File "/var/mycodo-root/env/lib/python3.9/site-packages/urllib3/poolmanager.py", line 376, in urlopen response = conn.urlopen(method, u.request_uri, kw) File "/var/mycodo-root/env/lib/python3.9/site-packages/urllib3/connectionpool.py", line 787, in urlopen retries = retries.increment( File "/var/mycodo-root/env/lib/python3.9/site-packages/urllib3/util/retry.py", line 525, in increment raise six.reraise(type(error), error, _stacktrace) File "/var/mycodo-root/env/lib/python3.9/site-packages/urllib3/packages/six.py", line 770, in reraise raise value File "/var/mycodo-root/env/lib/python3.9/site-packages/urllib3/connectionpool.py", line 703, in urlopen httplib_response = self._make_request( File "/var/mycodo-root/env/lib/python3.9/site-packages/urllib3/connectionpool.py", line 398, in _make_request conn.request(method, url, httplib_request_kw) File "/var/mycodo-root/env/lib/python3.9/site-packages/urllib3/connection.py", line 244, in request super(HTTPConnection, self).request(method, url, body=body, headers=headers) File "/usr/lib/python3.9/http/client.py", line 1255, in request self._send_request(method, url, body, headers, encode_chunked) File "/usr/lib/python3.9/http/client.py", line 1301, in _send_request self.endheaders(body, encode_chunked=encode_chunked) File "/usr/lib/python3.9/http/client.py", line 1250, in endheaders self._send_output(message_body, encode_chunked=encode_chunked) File "/usr/lib/python3.9/http/client.py", line 1010, in _send_output self.send(msg) File "/usr/lib/python3.9/http/client.py", line 950, in send self.connect() File "/var/mycodo-root/env/lib/python3.9/site-packages/urllib3/connection.py", line 205, in connect conn = self._new_conn() File "/var/mycodo-root/env/lib/python3.9/site-packages/urllib3/connection.py", line 186, in _new_conn raise NewConnectionError( urllib3.exceptions.NewConnectionError: <urllib3.connection.HTTPConnection object at 0x7f24351040>: Failed to establish a new connection: [Errno 111] Connection refused 2023-06-13 08:24:18,268 - INFO - mycodo - Received command to terminate daemon

LucidEye commented 1 year ago

OK... it crashed again this morning. It's happening about every 24 hours now :-( This time I actually caught it before it got stuck in the hang state for too long and after rebooting the Pi I was able to grab the log file lines at the time of the initial problem. I have gone through the following log lines and highlighted the errors in bold type. It looks like there is somehow a double time stamp on the initial error??? I have no idea how that could have happened. That line also shows the Mycodo Daemon "starting"??? Why would it be "starting"? It should already be running... I did not stop the daemon, and I don't have any functions or settings that would stop or start the daemon either? It's like the system is restarting itself, and I did nothing to cause this. I have checked all the electrical connections again, and nothing is wrong. There are also no other errors before that line, no warnings or indicators as to what might be causing the daemon to just restart on it's own? Any suggestions on how I should proceed in troubleshooting this?

2023-06-16 23:01:03,458 - INFO - mycodo.controllers.controller_trigger_6fdac2b6 - Deactivated in 65.5 ms 2023-06-16 23:01:03,713 - INFO - mycodo.controllers.controller_trigger_49d6c108 - Deactivated in 256.5 ms 2023-06-17 05:01:01,132 - INFO - mycodo.controllers.controller_trigger_49d6c108 - Activated in 341.1 ms 2023-06-17 05:01:01,798 - INFO - mycodo.controllers.controller_trigger_6fdac2b6 - Activated in 126.4 ms 2023-06-17 05:01:02,711 - INFO - mycodo.function.bang_bang_3397e924 - Bang-Bang controller started with options: Measurement Device: 6c261530-3ac8-4482-8800-8035cecf95cb, Measurement: d3460c2b-df14-4c72-b854-e4944ca156d9, Output: 4c46969e-de6d-4747-a582-738cea12d651, Output_Channel: 3, Setpoint: 0.9, Hysteresis: 0.03, Direction: lower, Period: 5.0 2023-06-17 05:01:02,718 - INFO - mycodo.controllers.controller_function_3397e924 - Activated in 447.1 ms NOTICE THE DOUBLE TIME STAMP ON THIS LINE-THIS IS WHERE I BELIEVE THE CASCADE BEGINS- 2023-06-17 09:41:29,22023-06-17 09:17:15,754 - INFO - mycodo - Mycodo daemon v8.15.8 starting 2023-06-17 09:17:15,782 - INFO - mycodo.pyro_daemon - Starting Pyro5 daemon 2023-06-17 09:17:16,531 - INFO - mycodo.outputs.on_off_gpio_cfaaccb0 - Output setup on pin 20 and turned OFF (ON=HIGH) 2023-06-17 09:17:16,532 - INFO - mycodo.outputs.on_off_gpio_cfaaccb0 - Initialized in 217.8 ms 2023-06-17 09:17:16,758 - INFO - mycodo.outputs.pwm_gpio_c0598a74 - Output setup on Any pin 18 at 22000 Hertz 2023-06-17 09:17:16,761 - INFO - mycodo.outputs.pwm_gpio_c0598a74 - PWM set to 30.0 % duty cycle (user-specified value) 2023-06-17 09:17:16,761 - INFO - mycodo.outputs.pwm_gpio_c0598a74 - Initialized in 227.9 ms 2023-06-17 09:17:17,047 - INFO - mycodo.outputs.on_off_gpio_d30253e9 - Output setup on pin 16 and turned OFF (ON=HIGH) 2023-06-17 09:17:17,048 - INFO - mycodo.outputs.on_off_gpio_d30253e9 - Initialized in 282.1 ms 2023-06-17 09:17:17,468 - INFO - mycodo.outputs.on_off_gpio_4a216c40 - Output setup on pin 21 and turned OFF (ON=HIGH) 2023-06-17 09:17:17,469 - INFO - mycodo.outputs.on_off_gpio_4a216c40 - Initialized in 419.0 ms 2023-06-17 09:17:18,821 - INFO - mycodo.outputs.on_off_wireless_rpi_rf_5318ad16 - Initialized in 1350.4 ms 2023-06-17 09:17:19,076 - INFO - mycodo.outputs.on_off_wireless_rpi_rf_0246af63 - Initialized in 244.9 ms 2023-06-17 09:17:19,252 - INFO - mycodo.outputs.on_off_wireless_rpi_rf_3f6e3c73 - Initialized in 173.4 ms 2023-06-17 09:17:19,550 - INFO - mycodo.outputs.on_off_gpio_ceb7418b - Output setup on pin 12 and turned OFF (ON=HIGH) 2023-06-17 09:17:19,551 - INFO - mycodo.outputs.on_off_gpio_ceb7418b - Initialized in 297.5 ms 2023-06-17 09:17:19,720 - INFO - mycodo.outputs.on_off_gpio_e4822e6a - Output setup on pin 22 and turned ON (ON=HIGH) 2023-06-17 09:17:19,721 - INFO - mycodo.outputs.on_off_gpio_e4822e6a - Initialized in 168.9 ms 2023-06-17 09:17:20,054 - INFO - mycodo.outputs.on_off_kasa_plugs_7ea0d727 - Starting asyncio RPC server... 2023-06-17 09:17:20,215 - INFO - mycodo.outputs.on_off_kasa_plugs_7ea0d727 - Initialized in 493.3 ms 2023-06-17 09:17:20,395 - INFO - mycodo.outputs.on_off_kasa_plugs_067fb7f3 - Starting asyncio RPC server... 2023-06-17 09:17:20,523 - INFO - mycodo.outputs.on_off_kasa_plugs_067fb7f3 - Initialized in 304.8 ms 2023-06-17 09:17:20,698 - INFO - mycodo.outputs.on_off_kasa_plugs_332f0a30 - Starting asyncio RPC server... 2023-06-17 09:17:20,841 - INFO - mycodo.outputs.on_off_kasa_plugs_332f0a30 - Initialized in 314.8 ms 2023-06-17 09:17:21,019 - INFO - mycodo.outputs.on_off_kasa_plugs_7be40a44 - Starting asyncio RPC server... 2023-06-17 09:17:21,145 - INFO - mycodo.outputs.on_off_kasa_plugs_7be40a44 - Initialized in 300.7 ms 2023-06-17 09:17:21,329 - INFO - mycodo.outputs.on_off_kasa_hs300_0_4_2_4c46969e - Starting asyncio RPC server... 2023-06-17 09:17:27,229 - INFO - mycodo.outputs.on_off_kasa_hs300_0_4_2_4c46969e - Initialized in 6081.8 ms 2023-06-17 09:17:27,491 - INFO - mycodo.outputs.on_off_shell_39437c56 - Initialized in 258.5 ms 2023-06-17 09:17:27,492 - INFO - mycodo.controllers.controller_output - Activated in 11489.9 ms 2023-06-17 09:17:28,177 - INFO - mycodo.controllers.controller_conditional_a0417b2a - Activated in 70.7 ms 2023-06-17 09:17:28,386 - INFO - mycodo.controllers.controller_conditional_90a2bfdd - Activated in 86.1 ms 2023-06-17 09:17:28,651 - INFO - mycodo.controllers.controller_conditional_45c4d3c5 - Activated in 86.2 ms 2023-06-17 09:17:29,047 - INFO - mycodo.controllers.controller_conditional_c180b54a - Activated in 170.2 ms 2023-06-17 09:17:29,854 - INFO - mycodo.controllers.controller_conditional_8cb60bed - Activated in 177.1 ms 2023-06-17 09:17:30,452 - INFO - mycodo.controllers.controller_conditional_31d0988f - Activated in 215.2 ms 2023-06-17 09:17:30,847 - INFO - mycodo.controllers.controller_conditional_7afb1b88 - Activated in 80.7 ms 2023-06-17 09:17:30,850 - INFO - mycodo - All activated Conditional controllers started 2023-06-17 09:17:31,291 - INFO - mycodo.controllers.controller_trigger_092b8380 - Activated in 176.6 ms 2023-06-17 09:17:31,610 - INFO - mycodo.controllers.controller_trigger_6fdac2b6 - Activated in 124.1 ms 2023-06-17 09:17:31,880 - INFO - mycodo.controllers.controller_trigger_49d6c108 - Activated in 80.2 ms 2023-06-17 09:17:32,092 - INFO - mycodo.controllers.controller_trigger_5c72de1e - Activated in 106.5 ms 2023-06-17 09:17:32,285 - INFO - mycodo.controllers.controller_trigger_7a18fa7b - Activated in 78.7 ms 2023-06-17 09:17:32,496 - INFO - mycodo.controllers.controller_trigger_1d11f1a1 - Activated in 94.7 ms 2023-06-17 09:17:32,684 - INFO - mycodo.controllers.controller_trigger_e48f7e07 - Activated in 91.0 ms 2023-06-17 09:17:32,891 - INFO - mycodo.controllers.controller_trigger_9efb3322 - Activated in 98.7 ms 2023-06-17 09:17:33,382 - INFO - mycodo.controllers.controller_trigger_a3825040 - Activated in 73.2 ms 2023-06-17 09:17:33,574 - INFO - mycodo.controllers.controller_trigger_284bb790 - Activated in 90.6 ms 2023-06-17 09:17:33,819 - INFO - mycodo.controllers.controller_trigger_4bb4cc1e - Activated in 153.4 ms 2023-06-17 09:17:34,163 - INFO - mycodo.controllers.controller_trigger_ddb8d1c8 - Activated in 112.0 ms 2023-06-17 09:17:34,741 - INFO - mycodo.controllers.controller_trigger_b0eda3a4 - Activated in 304.2 ms 2023-06-17 09:17:35,099 - INFO - mycodo.controllers.controller_trigger_93bffa38 - Activated in 166.3 ms 2023-06-17 09:17:35,100 - INFO - mycodo - All activated Trigger controllers started 2023-06-17 09:17:35,865 - ERROR - mycodo.inputs.rpi_cpu_gpu_temperature_9ec8173c - Option 'path_temperature_cpu' required but was not found to be set by the user. Setting to default (/sys/class/thermal/thermal_zone0/temp). 2023-06-17 09:17:35,866 - ERROR - mycodo.inputs.rpi_cpu_gpu_temperature_9ec8173c - Option 'path_temperature_gpu' required but was not found to be set by the user. Setting to default (/usr/bin/vcgencmd). 2023-06-17 09:17:35,866 - INFO - mycodo.controllers.controller_input_9ec8173c - Activated in 565.0 ms 2023-06-17 09:17:36,609 - INFO - mycodo.controllers.controller_input_893af301 - Activated in 544.4 ms 2023-06-17 09:17:37,557 - INFO - mycodo.controllers.controller_input_d481115f - Activated in 753.0 ms 2023-06-17 09:17:38,365 - INFO - mycodo.controllers.controller_input_d7f4d84e - Activated in 658.1 ms 2023-06-17 09:17:38,842 - INFO - mycodo.controllers.controller_input_9c2407ce - Activated in 352.6 ms 2023-06-17 09:17:40,429 - INFO - mycodo.controllers.controller_input_50b2f163 - Activated in 1265.5 ms 2023-06-17 09:17:40,448 - INFO - mycodo.inputs.mqtt_paho_50b2f163 - Connected to 192.168.3.39 as client_tGJz5bx0 2023-06-17 09:17:41,866 - INFO - mycodo.controllers.controller_input_ef2eb196 - Activated in 1209.5 ms 2023-06-17 09:17:41,889 - INFO - mycodo.inputs.mqtt_paho_ef2eb196 - Connected to 192.168.3.39 as client_mHgn0zgD 2023-06-17 09:17:42,668 - INFO - mycodo.controllers.controller_input_fc05a536 - Activated in 616.9 ms 2023-06-17 09:17:43,068 - INFO - mycodo.controllers.controller_input_0f2a2b1a - Activated in 258.0 ms 2023-06-17 09:17:44,427 - INFO - mycodo.controllers.controller_input_4ee54732 - Activated in 1256.3 ms 2023-06-17 09:17:44,428 - INFO - mycodo - All activated Input controllers started 2023-06-17 09:17:44,475 - INFO - mycodo - All activated PID controllers started THIS IS WHERE I REBOOTED THE PI- 2023-06-17 09:43:53,991 - INFO - mycodo.function.bang_bang_3397e924 - Bang-Bang controller started with options: Measurement Device: 6c261530-3ac8-4482-8800-8035cecf95cb, Measurement: d3460c2b-df14-4c72-b854-e4944ca156d9, Output: 4c46969e-de6d-4747-a582-738cea12d651, Output_Channel: 3, Setpoint: 0.9, Hysteresis: 0.03, Direction: lower, Period: 5.0 2023-06-17 09:43:54,046 - INFO - mycodo.controllers.controller_function_3397e924 - Activated in 4229.5 ms 2023-06-17 09:43:55,976 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-17 09:43:57,581 - INFO - mycodo.controllers.controller_function_6c261530 - Activated in 2370.4 ms 2023-06-17 09:43:57,585 - INFO - mycodo - All activated Function controllers started 2023-06-17 09:43:59,698 - ERROR - mycodo.function.bang_bang_3397e924 - Could not acquire a measurement 2023-06-17 09:44:05,433 - INFO - mycodo.controllers.controller_widget - Activated in 7833.1 ms 2023-06-17 09:44:06,440 - INFO - mycodo - Mycodo daemon started in 45.728 seconds

Here is the graph from my system monitor dashboard. You can see the "glitch" in the CPU load where the problem happens, as well as a rise in CPU temp. But I have no idea what process is causing this to happen.

Screenshot at 2023-06-17 10-15-41

LucidEye commented 1 year ago

The system was crashed again this morning when I woke up... and the humidifier was stuck on for over an hour. I really need some answers as to why this keeps happening. Can you please offer some suggestions as to what might be causing this?

kizniche commented 1 year ago

I have no idea what process is causing this to happen

This is what you need to know if you want to figure out what the issue is.

LucidEye commented 1 year ago

I have no idea what process is causing this to happen

This is what you need to know if you want to figure out what the issue is.

How am I supposed to figure that out if the log doesn't show anything?

LucidEye commented 1 year ago

I found this in the OS Syslog at the time the Mycodo Dashboard graph shows the CPU at it's highest usage:

Jun 19 05:00:32 Mycodo-LIVE python[475]: 2023-06-19 05:00:32,040 ending receiver Jun 19 05:00:32 Mycodo-LIVE python[475]: 2023-06-19 05:00:32,258 Reached max_close_wait (300.0 seconds) waiting for batches to finish writing. Force closing Jun 19 05:00:32 Mycodo-LIVE python[475]: 2023-06-19 05:00:32,667 Reached max_close_wait (300.0 seconds) waiting for batches to finish writing. Force closing Jun 19 05:00:35 Mycodo-LIVE python[475]: 2023-06-19 05:00:35,329 Reached max_close_wait (300.0 seconds) waiting for batches to finish writing. Force closing Jun 19 05:00:36 Mycodo-LIVE python[475]: 2023-06-19 05:00:36,949 Reached max_close_wait (300.0 seconds) waiting for batches to finish writing. Force closing Jun 19 05:00:38 Mycodo-LIVE python[475]: 2023-06-19 05:00:38,050 Reached max_close_wait (300.0 seconds) waiting for batches to finish writing. Force closing Jun 19 05:00:38 Mycodo-LIVE python[475]: 2023-06-19 05:00:38,072 Reached max_close_wait (300.0 seconds) waiting for batches to finish writing. Force closing Jun 19 05:00:38 Mycodo-LIVE python[475]: 2023-06-19 05:00:38,906 Reached max_close_wait (300.0 seconds) waiting for batches to finish writing. Force closing Jun 19 05:00:39 Mycodo-LIVE python[475]: 2023-06-19 05:00:39,103 Reached max_close_wait (300.0 seconds) waiting for batches to finish writing. Force closing Jun 19 05:00:39 Mycodo-LIVE python[475]: 2023-06-19 05:00:39,186 Reached max_close_wait (300.0 seconds) waiting for batches to finish writing. Force closing Jun 19 05:00:39 Mycodo-LIVE python[475]: 2023-06-19 05:00:39,533 Retrying (WritesRetry(total=0, connect=None, read=None, redirect=None, status=None)) after connection broken by 'ReadTimeoutError("HTTPConnectionPool(host='localhost', port=8086): Read timed out. (read timeout=4.9936172440066)")': /api/v2/write?org=mycodo&bucket=mycodo_db&precision=ns Jun 19 05:00:40 Mycodo-LIVE python[475]: 2023-06-19 05:00:40,487 Reached max_close_wait (300.0 seconds) waiting for batches to finish writing. Force closing Jun 19 05:00:40 Mycodo-LIVE python[475]: 2023-06-19 05:00:40,806 starting receiver Jun 19 05:00:40 Mycodo-LIVE python[475]: 2023-06-19 05:00:40,808 starting receiver Jun 19 05:00:40 Mycodo-LIVE python[475]: 2023-06-19 05:00:40,875 starting receiver Jun 19 05:00:41 Mycodo-LIVE python[475]: 2023-06-19 05:00:41,013 Task was destroyed but it is pending! Jun 19 05:00:41 Mycodo-LIVE python[475]: task: <Task pending name='Task-424883' coro=<Client._receiver() running at /var/mycodo-root/env/lib/python3.9/site-packages/aio_msgpack_rpc/client.py:47> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7eda570160>()]>> Jun 19 05:00:41 Mycodo-LIVE python[475]: 2023-06-19 05:00:41,015 Task was destroyed but it is pending! Jun 19 05:00:41 Mycodo-LIVE python[475]: task: <Task pending name='Task-424886' coro=<Client._receiver() running at /var/mycodo-root/env/lib/python3.9/site-packages/aio_msgpack_rpc/client.py:47> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7ed8e54280>()]>> Jun 19 05:00:41 Mycodo-LIVE python[475]: 2023-06-19 05:00:41,015 ending receiver Jun 19 05:00:41 Mycodo-LIVE python[475]: 2023-06-19 05:00:41,015 ending receiver Jun 19 05:00:41 Mycodo-LIVE python[475]: 2023-06-19 05:00:41,016 Task was destroyed but it is pending! Jun 19 05:00:41 Mycodo-LIVE python[475]: task: <Task pending name='Task-424892' coro=<Client._receiver() running at /var/mycodo-root/env/lib/python3.9/site-packages/aio_msgpack_rpc/client.py:47> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7e92b7c5e0>()]>> Jun 19 05:00:41 Mycodo-LIVE python[475]: 2023-06-19 05:00:41,017 ending receiver Jun 19 05:00:41 Mycodo-LIVE python[475]: 2023-06-19 05:00:41,731 starting receiver Jun 19 05:00:41 Mycodo-LIVE python[475]: 2023-06-19 05:00:41,762 Reached max_close_wait (300.0 seconds) waiting for batches to finish writing. Force closing Jun 19 05:00:41 Mycodo-LIVE python[475]: 2023-06-19 05:00:41,826 Task was destroyed but it is pending! Jun 19 05:00:41 Mycodo-LIVE python[475]: task: <Task pending name='Task-424896' coro=<Client._receiver() running at /var/mycodo-root/env/lib/python3.9/site-packages/aio_msgpack_rpc/client.py:47> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7eb90c6730>()]>> Jun 19 05:00:41 Mycodo-LIVE python[475]: 2023-06-19 05:00:41,828 ending receiver Jun 19 05:00:41 Mycodo-LIVE python[475]: 2023-06-19 05:00:41,931 Reached max_close_wait (300.0 seconds) waiting for batches to finish writing. Force closing Jun 19 05:00:43 Mycodo-LIVE python[475]: /var/mycodo-root/env/lib/python3.9/site-packages/urllib3/connectionpool.py:1045: InsecureRequestWarning: Unverified HTTPS request is being made to host '127.0.0.1'. Adding certificate verification is strongly advised. See: https://urllib3.readthedocs.io/en/1.26.x/advanced-usage.html#ssl-warnings Jun 19 05:00:43 Mycodo-LIVE python[475]: warnings.warn( Jun 19 05:00:43 Mycodo-LIVE python[588]: 2023-06-19 05:00:43,149 Exception raised while handling cache file '/home/pi/Mycodo/mycodo/flask_session/58f60128340584c9086a3d4c58e0dbfd' Jun 19 05:00:43 Mycodo-LIVE python[588]: Traceback (most recent call last): Jun 19 05:00:43 Mycodo-LIVE python[588]: File "/var/mycodo-root/env/lib/python3.9/site-packages/cachelib/file.py", line 122, in _remove_expired Jun 19 05:00:43 Mycodo-LIVE python[588]: expires = struct.unpack("I", f.read(4))[0] Jun 19 05:00:43 Mycodo-LIVE python[588]: struct.error: unpack requires a buffer of 4 bytes Jun 19 05:00:43 Mycodo-LIVE python[588]: 2023-06-19 05:00:43,157 Exception raised while handling cache file '/home/pi/Mycodo/mycodo/flask_session/f34bf0f3d8f1b4eef1c7ced2d4045403' Jun 19 05:00:43 Mycodo-LIVE python[588]: Traceback (most recent call last): Jun 19 05:00:43 Mycodo-LIVE python[588]: File "/var/mycodo-root/env/lib/python3.9/site-packages/cachelib/file.py", line 122, in _remove_expired Jun 19 05:00:43 Mycodo-LIVE python[588]: expires = struct.unpack("I", f.read(4))[0] Jun 19 05:00:43 Mycodo-LIVE python[588]: struct.error: unpack requires a buffer of 4 bytes Jun 19 05:00:43 Mycodo-LIVE python[588]: 2023-06-19 05:00:43,159 Exception raised while handling cache file '/home/pi/Mycodo/mycodo/flask_session/bc5f250236d0a36b4011a49cd6710ff6' Jun 19 05:00:43 Mycodo-LIVE python[588]: Traceback (most recent call last): Jun 19 05:00:43 Mycodo-LIVE python[588]: File "/var/mycodo-root/env/lib/python3.9/site-packages/cachelib/file.py", line 122, in _remove_expired Jun 19 05:00:43 Mycodo-LIVE python[588]: expires = struct.unpack("I", f.read(4))[0] Jun 19 05:00:43 Mycodo-LIVE python[588]: struct.error: unpack requires a buffer of 4 bytes Jun 19 05:00:43 Mycodo-LIVE python[588]: 2023-06-19 05:00:43,160 Exception raised while handling cache file '/home/pi/Mycodo/mycodo/flask_session/2f992799dccf27368656b02094c55ef9' Jun 19 05:00:43 Mycodo-LIVE python[588]: Traceback (most recent call last): Jun 19 05:00:43 Mycodo-LIVE python[588]: File "/var/mycodo-root/env/lib/python3.9/site-packages/cachelib/file.py", line 122, in _remove_expired Jun 19 05:00:43 Mycodo-LIVE python[588]: expires = struct.unpack("I", f.read(4))[0] Jun 19 05:00:43 Mycodo-LIVE python[588]: struct.error: unpack requires a buffer of 4 bytes Jun 19 05:00:43 Mycodo-LIVE python[588]: 2023-06-19 05:00:43,172 Exception raised while handling cache file '/home/pi/Mycodo/mycodo/flask_session/8231ffa779ac9e9cae248b3d09d11a95' Jun 19 05:00:43 Mycodo-LIVE python[588]: Traceback (most recent call last): Jun 19 05:00:43 Mycodo-LIVE python[588]: File "/var/mycodo-root/env/lib/python3.9/site-packages/cachelib/file.py", line 122, in _remove_expired Jun 19 05:00:43 Mycodo-LIVE python[588]: expires = struct.unpack("I", f.read(4))[0] Jun 19 05:00:43 Mycodo-LIVE python[588]: struct.error: unpack requires a buffer of 4 bytes Jun 19 05:00:43 Mycodo-LIVE python[588]: 2023-06-19 05:00:43,186 Exception raised while handling cache file '/home/pi/Mycodo/mycodo/flask_session/4b939dbb614d848c764edf6c6e30ac55' Jun 19 05:00:43 Mycodo-LIVE python[588]: Traceback (most recent call last): Jun 19 05:00:43 Mycodo-LIVE python[588]: File "/var/mycodo-root/env/lib/python3.9/site-packages/cachelib/file.py", line 122, in _remove_expired Jun 19 05:00:43 Mycodo-LIVE python[588]: expires = struct.unpack("I", f.read(4))[0] Jun 19 05:00:43 Mycodo-LIVE python[588]: struct.error: unpack requires a buffer of 4 bytes Jun 19 05:00:43 Mycodo-LIVE python[588]: 2023-06-19 05:00:43,187 Exception raised while handling cache file '/home/pi/Mycodo/mycodo/flask_session/f5ab6debc4050b2ab6491d446cb3f159' Jun 19 05:00:43 Mycodo-LIVE python[588]: Traceback (most recent call last): Jun 19 05:00:43 Mycodo-LIVE python[588]: File "/var/mycodo-root/env/lib/python3.9/site-packages/cachelib/file.py", line 122, in _remove_expired Jun 19 05:00:43 Mycodo-LIVE python[588]: expires = struct.unpack("I", f.read(4))[0] Jun 19 05:00:43 Mycodo-LIVE python[588]: struct.error: unpack requires a buffer of 4 bytes Jun 19 05:00:43 Mycodo-LIVE python[588]: 2023-06-19 05:00:43,190 Exception raised while handling cache file '/home/pi/Mycodo/mycodo/flask_session/eb66432cb2d2b463de517d111f4b5185' Jun 19 05:00:43 Mycodo-LIVE python[588]: Traceback (most recent call last): Jun 19 05:00:43 Mycodo-LIVE python[588]: File "/var/mycodo-root/env/lib/python3.9/site-packages/cachelib/file.py", line 122, in _remove_expired Jun 19 05:00:43 Mycodo-LIVE python[588]: expires = struct.unpack("I", f.read(4))[0] Jun 19 05:00:43 Mycodo-LIVE python[588]: struct.error: unpack requires a buffer of 4 bytes Jun 19 05:00:43 Mycodo-LIVE python[588]: 2023-06-19 05:00:43,194 Exception raised while handling cache file '/home/pi/Mycodo/mycodo/flask_session/ef3822c50e7300784123e8979ded2f7b' Jun 19 05:00:43 Mycodo-LIVE python[588]: Traceback (most recent call last): Jun 19 05:00:43 Mycodo-LIVE python[588]: File "/var/mycodo-root/env/lib/python3.9/site-packages/cachelib/file.py", line 122, in _remove_expired Jun 19 05:00:43 Mycodo-LIVE python[588]: expires = struct.unpack("I", f.read(4))[0] Jun 19 05:00:43 Mycodo-LIVE python[588]: struct.error: unpack requires a buffer of 4 bytes Jun 19 05:00:43 Mycodo-LIVE python[588]: 2023-06-19 05:00:43,198 Exception raised while handling cache file '/home/pi/Mycodo/mycodo/flask_session/8ad911235f6a0cd8a4ae5c6d92640e2a' Jun 19 05:00:43 Mycodo-LIVE python[588]: Traceback (most recent call last): Jun 19 05:00:43 Mycodo-LIVE python[588]: File "/var/mycodo-root/env/lib/python3.9/site-packages/cachelib/file.py", line 122, in _remove_expired Jun 19 05:00:43 Mycodo-LIVE python[588]: expires = struct.unpack("I", f.read(4))[0] Jun 19 05:00:43 Mycodo-LIVE python[588]: struct.error: unpack requires a buffer of 4 bytes Jun 19 05:00:43 Mycodo-LIVE python[588]: 2023-06-19 05:00:43,200 Exception raised while handling cache file '/home/pi/Mycodo/mycodo/flask_session/0ed81a41065ec670b53656c8b0863bf9' Jun 19 05:00:43 Mycodo-LIVE python[588]: Traceback (most recent call last): Jun 19 05:00:43 Mycodo-LIVE python[588]: File "/var/mycodo-root/env/lib/python3.9/site-packages/cachelib/file.py", line 122, in _remove_expired Jun 19 05:00:43 Mycodo-LIVE python[588]: expires = struct.unpack("I", f.read(4))[0] Jun 19 05:00:43 Mycodo-LIVE python[588]: struct.error: unpack requires a buffer of 4 bytes Jun 19 05:00:43 Mycodo-LIVE python[588]: 2023-06-19 05:00:43,203 Exception raised while handling cache file '/home/pi/Mycodo/mycodo/flask_session/488ca5c5e6aa2cd683e42d9d84b036de' Jun 19 05:00:43 Mycodo-LIVE python[588]: Traceback (most recent call last): Jun 19 05:00:43 Mycodo-LIVE python[588]: File "/var/mycodo-root/env/lib/python3.9/site-packages/cachelib/file.py", line 122, in _remove_expired Jun 19 05:00:43 Mycodo-LIVE python[588]: expires = struct.unpack("I", f.read(4))[0] Jun 19 05:00:43 Mycodo-LIVE python[588]: struct.error: unpack requires a buffer of 4 bytes Jun 19 05:00:43 Mycodo-LIVE python[588]: 2023-06-19 05:00:43,204 Exception raised while handling cache file '/home/pi/Mycodo/mycodo/flask_session/524014d79c4d213ecf17eca8ee3eaed7' Jun 19 05:00:43 Mycodo-LIVE python[588]: Traceback (most recent call last): Jun 19 05:00:43 Mycodo-LIVE python[588]: File "/var/mycodo-root/env/lib/python3.9/site-packages/cachelib/file.py", line 122, in _remove_expired Jun 19 05:00:43 Mycodo-LIVE python[588]: expires = struct.unpack("I", f.read(4))[0] Jun 19 05:00:43 Mycodo-LIVE python[588]: struct.error: unpack requires a buffer of 4 bytes Jun 19 05:00:43 Mycodo-LIVE python[588]: 2023-06-19 05:00:43,206 Exception raised while handling cache file '/home/pi/Mycodo/mycodo/flask_session/1d2fc252bdb0eb4a499e2db3703961b6' Jun 19 05:00:43 Mycodo-LIVE python[588]: Traceback (most recent call last): Jun 19 05:00:43 Mycodo-LIVE python[588]: File "/var/mycodo-root/env/lib/python3.9/site-packages/cachelib/file.py", line 122, in _remove_expired Jun 19 05:00:43 Mycodo-LIVE python[588]: expires = struct.unpack("I", f.read(4))[0] Jun 19 05:00:43 Mycodo-LIVE python[588]: struct.error: unpack requires a buffer of 4 bytes Jun 19 05:00:43 Mycodo-LIVE python[588]: 2023-06-19 05:00:43,207 Exception raised while handling cache file '/home/pi/Mycodo/mycodo/flask_session/9b57ccfc2d39207f9c6784711543e686' Jun 19 05:00:43 Mycodo-LIVE python[588]: Traceback (most recent call last): Jun 19 05:00:43 Mycodo-LIVE python[588]: File "/var/mycodo-root/env/lib/python3.9/site-packages/cachelib/file.py", line 122, in _remove_expired Jun 19 05:00:43 Mycodo-LIVE python[588]: expires = struct.unpack("I", f.read(4))[0] Jun 19 05:00:43 Mycodo-LIVE python[588]: struct.error: unpack requires a buffer of 4 bytes Jun 19 05:00:43 Mycodo-LIVE python[588]: 2023-06-19 05:00:43,213 Exception raised while handling cache file '/home/pi/Mycodo/mycodo/flask_session/58f60128340584c9086a3d4c58e0dbfd' Jun 19 05:00:43 Mycodo-LIVE python[588]: Traceback (most recent call last): Jun 19 05:00:43 Mycodo-LIVE python[588]: File "/var/mycodo-root/env/lib/python3.9/site-packages/cachelib/file.py", line 140, in _remove_older Jun 19 05:00:43 Mycodo-LIVE python[588]: timestamp = struct.unpack("I", f.read(4))[0] Jun 19 05:00:43 Mycodo-LIVE python[588]: struct.error: unpack requires a buffer of 4 bytes Jun 19 05:00:43 Mycodo-LIVE python[588]: 2023-06-19 05:00:43,221 Exception raised while handling cache file '/home/pi/Mycodo/mycodo/flask_session/f34bf0f3d8f1b4eef1c7ced2d4045403' Jun 19 05:00:43 Mycodo-LIVE python[588]: Traceback (most recent call last): Jun 19 05:00:43 Mycodo-LIVE python[588]: File "/var/mycodo-root/env/lib/python3.9/site-packages/cachelib/file.py", line 140, in _remove_older Jun 19 05:00:43 Mycodo-LIVE python[588]: timestamp = struct.unpack("I", f.read(4))[0] Jun 19 05:00:43 Mycodo-LIVE python[588]: struct.error: unpack requires a buffer of 4 bytes Jun 19 05:00:43 Mycodo-LIVE python[588]: 2023-06-19 05:00:43,223 Exception raised while handling cache file '/home/pi/Mycodo/mycodo/flask_session/bc5f250236d0a36b4011a49cd6710ff6' Jun 19 05:00:43 Mycodo-LIVE python[588]: Traceback (most recent call last): Jun 19 05:00:43 Mycodo-LIVE python[588]: File "/var/mycodo-root/env/lib/python3.9/site-packages/cachelib/file.py", line 140, in _remove_older Jun 19 05:00:43 Mycodo-LIVE python[588]: timestamp = struct.unpack("I", f.read(4))[0] Jun 19 05:00:43 Mycodo-LIVE python[588]: struct.error: unpack requires a buffer of 4 bytes Jun 19 05:00:43 Mycodo-LIVE python[588]: 2023-06-19 05:00:43,224 Exception raised while handling cache file '/home/pi/Mycodo/mycodo/flask_session/2f992799dccf27368656b02094c55ef9' Jun 19 05:00:43 Mycodo-LIVE python[588]: Traceback (most recent call last): Jun 19 05:00:43 Mycodo-LIVE python[588]: File "/var/mycodo-root/env/lib/python3.9/site-packages/cachelib/file.py", line 140, in _remove_older Jun 19 05:00:43 Mycodo-LIVE python[588]: timestamp = struct.unpack("I", f.read(4))[0] Jun 19 05:00:43 Mycodo-LIVE python[588]: struct.error: unpack requires a buffer of 4 bytes Jun 19 05:00:43 Mycodo-LIVE python[588]: 2023-06-19 05:00:43,236 Exception raised while handling cache file '/home/pi/Mycodo/mycodo/flask_session/8231ffa779ac9e9cae248b3d09d11a95' Jun 19 05:00:43 Mycodo-LIVE python[588]: Traceback (most recent call last): Jun 19 05:00:43 Mycodo-LIVE python[588]: File "/var/mycodo-root/env/lib/python3.9/site-packages/cachelib/file.py", line 140, in _remove_older Jun 19 05:00:43 Mycodo-LIVE python[588]: timestamp = struct.unpack("I", f.read(4))[0] Jun 19 05:00:43 Mycodo-LIVE python[588]: struct.error: unpack requires a buffer of 4 bytes Jun 19 05:00:43 Mycodo-LIVE python[588]: 2023-06-19 05:00:43,246 Exception raised while handling cache file '/home/pi/Mycodo/mycodo/flask_session/4b939dbb614d848c764edf6c6e30ac55' Jun 19 05:00:43 Mycodo-LIVE python[588]: Traceback (most recent call last): Jun 19 05:00:43 Mycodo-LIVE python[588]: File "/var/mycodo-root/env/lib/python3.9/site-packages/cachelib/file.py", line 140, in _remove_older Jun 19 05:00:43 Mycodo-LIVE python[588]: timestamp = struct.unpack("I", f.read(4))[0] Jun 19 05:00:43 Mycodo-LIVE python[588]: struct.error: unpack requires a buffer of 4 bytes Jun 19 05:00:43 Mycodo-LIVE python[588]: 2023-06-19 05:00:43,247 Exception raised while handling cache file '/home/pi/Mycodo/mycodo/flask_session/f5ab6debc4050b2ab6491d446cb3f159' Jun 19 05:00:43 Mycodo-LIVE python[588]: Traceback (most recent call last): Jun 19 05:00:43 Mycodo-LIVE python[588]: File "/var/mycodo-root/env/lib/python3.9/site-packages/cachelib/file.py", line 140, in _remove_older Jun 19 05:00:43 Mycodo-LIVE python[588]: timestamp = struct.unpack("I", f.read(4))[0] Jun 19 05:00:43 Mycodo-LIVE python[588]: struct.error: unpack requires a buffer of 4 bytes Jun 19 05:00:43 Mycodo-LIVE python[588]: 2023-06-19 05:00:43,250 Exception raised while handling cache file '/home/pi/Mycodo/mycodo/flask_session/eb66432cb2d2b463de517d111f4b5185' Jun 19 05:00:43 Mycodo-LIVE python[588]: Traceback (most recent call last): Jun 19 05:00:43 Mycodo-LIVE python[588]: File "/var/mycodo-root/env/lib/python3.9/site-packages/cachelib/file.py", line 140, in _remove_older Jun 19 05:00:43 Mycodo-LIVE python[588]: timestamp = struct.unpack("I", f.read(4))[0] Jun 19 05:00:43 Mycodo-LIVE python[588]: struct.error: unpack requires a buffer of 4 bytes Jun 19 05:00:43 Mycodo-LIVE python[588]: 2023-06-19 05:00:43,253 Exception raised while handling cache file '/home/pi/Mycodo/mycodo/flask_session/ef3822c50e7300784123e8979ded2f7b' Jun 19 05:00:43 Mycodo-LIVE python[588]: Traceback (most recent call last): Jun 19 05:00:43 Mycodo-LIVE python[588]: File "/var/mycodo-root/env/lib/python3.9/site-packages/cachelib/file.py", line 140, in _remove_older Jun 19 05:00:43 Mycodo-LIVE python[588]: timestamp = struct.unpack("I", f.read(4))[0] Jun 19 05:00:43 Mycodo-LIVE python[588]: struct.error: unpack requires a buffer of 4 bytes Jun 19 05:00:43 Mycodo-LIVE python[588]: 2023-06-19 05:00:43,257 Exception raised while handling cache file '/home/pi/Mycodo/mycodo/flask_session/8ad911235f6a0cd8a4ae5c6d92640e2a' Jun 19 05:00:43 Mycodo-LIVE python[588]: Traceback (most recent call last): Jun 19 05:00:43 Mycodo-LIVE python[588]: File "/var/mycodo-root/env/lib/python3.9/site-packages/cachelib/file.py", line 140, in _remove_older Jun 19 05:00:43 Mycodo-LIVE python[588]: timestamp = struct.unpack("I", f.read(4))[0] Jun 19 05:00:43 Mycodo-LIVE python[588]: struct.error: unpack requires a buffer of 4 bytes Jun 19 05:00:43 Mycodo-LIVE python[588]: 2023-06-19 05:00:43,259 Exception raised while handling cache file '/home/pi/Mycodo/mycodo/flask_session/0ed81a41065ec670b53656c8b0863bf9' Jun 19 05:00:43 Mycodo-LIVE python[588]: Traceback (most recent call last): Jun 19 05:00:43 Mycodo-LIVE python[588]: File "/var/mycodo-root/env/lib/python3.9/site-packages/cachelib/file.py", line 140, in _remove_older Jun 19 05:00:43 Mycodo-LIVE python[588]: timestamp = struct.unpack("I", f.read(4))[0] Jun 19 05:00:43 Mycodo-LIVE python[588]: struct.error: unpack requires a buffer of 4 bytes Jun 19 05:00:43 Mycodo-LIVE python[588]: 2023-06-19 05:00:43,262 Exception raised while handling cache file '/home/pi/Mycodo/mycodo/flask_session/488ca5c5e6aa2cd683e42d9d84b036de' Jun 19 05:00:43 Mycodo-LIVE python[588]: Traceback (most recent call last): Jun 19 05:00:43 Mycodo-LIVE python[588]: File "/var/mycodo-root/env/lib/python3.9/site-packages/cachelib/file.py", line 140, in _remove_older Jun 19 05:00:43 Mycodo-LIVE python[588]: timestamp = struct.unpack("I", f.read(4))[0] Jun 19 05:00:43 Mycodo-LIVE python[588]: struct.error: unpack requires a buffer of 4 bytes Jun 19 05:00:43 Mycodo-LIVE python[588]: 2023-06-19 05:00:43,264 Exception raised while handling cache file '/home/pi/Mycodo/mycodo/flask_session/524014d79c4d213ecf17eca8ee3eaed7' Jun 19 05:00:43 Mycodo-LIVE python[588]: Traceback (most recent call last): Jun 19 05:00:43 Mycodo-LIVE python[588]: File "/var/mycodo-root/env/lib/python3.9/site-packages/cachelib/file.py", line 140, in _remove_older Jun 19 05:00:43 Mycodo-LIVE python[588]: timestamp = struct.unpack("I", f.read(4))[0] Jun 19 05:00:43 Mycodo-LIVE python[588]: struct.error: unpack requires a buffer of 4 bytes Jun 19 05:00:43 Mycodo-LIVE python[588]: 2023-06-19 05:00:43,265 Exception raised while handling cache file '/home/pi/Mycodo/mycodo/flask_session/1d2fc252bdb0eb4a499e2db3703961b6' Jun 19 05:00:43 Mycodo-LIVE python[588]: Traceback (most recent call last): Jun 19 05:00:43 Mycodo-LIVE python[588]: File "/var/mycodo-root/env/lib/python3.9/site-packages/cachelib/file.py", line 140, in _remove_older Jun 19 05:00:43 Mycodo-LIVE python[588]: timestamp = struct.unpack("I", f.read(4))[0] Jun 19 05:00:43 Mycodo-LIVE python[588]: struct.error: unpack requires a buffer of 4 bytes Jun 19 05:00:43 Mycodo-LIVE python[588]: 2023-06-19 05:00:43,267 Exception raised while handling cache file '/home/pi/Mycodo/mycodo/flask_session/9b57ccfc2d39207f9c6784711543e686' Jun 19 05:00:43 Mycodo-LIVE python[588]: Traceback (most recent call last): Jun 19 05:00:43 Mycodo-LIVE python[588]: File "/var/mycodo-root/env/lib/python3.9/site-packages/cachelib/file.py", line 140, in _remove_older Jun 19 05:00:43 Mycodo-LIVE python[588]: timestamp = struct.unpack("I", f.read(4))[0] Jun 19 05:00:43 Mycodo-LIVE python[588]: struct.error: unpack requires a buffer of 4 bytes Jun 19 05:00:51 Mycodo-LIVE python[475]: 2023-06-19 05:00:51,774 The batch item wasn't processed successfully because: HTTPConnectionPool(host='localhost', port=8086): Max retries exceeded with url: /api/v2/write?org=mycodo&bucket=mycodo_db&precision=ns (Caused by ReadTimeoutError("HTTPConnectionPool(host='localhost', port=8086): Read timed out. (read timeout=4.994303537008818)")) Jun 19 05:00:51 Mycodo-LIVE python[475]: 2023-06-19 05:00:51,803 starting receiver Jun 19 05:00:51 Mycodo-LIVE python[475]: 2023-06-19 05:00:51,862 starting receiver Jun 19 05:00:51 Mycodo-LIVE python[475]: 2023-06-19 05:00:51,911 starting receiver Jun 19 05:00:51 Mycodo-LIVE python[475]: 2023-06-19 05:00:51,920 starting receiver Jun 19 05:00:52 Mycodo-LIVE python[475]: 2023-06-19 05:00:52,163 ending receiver Jun 19 05:00:52 Mycodo-LIVE python[475]: 2023-06-19 05:00:52,231 Task was destroyed but it is pending! Jun 19 05:00:52 Mycodo-LIVE python[475]: task: <Task pending name='Task-424909' coro=<Client._receiver() done, defined at /var/mycodo-root/env/lib/python3.9/site-packages/aio_msgpack_rpc/client.py:37> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7eda1e19d0>()]>> Jun 19 05:00:52 Mycodo-LIVE python[475]: 2023-06-19 05:00:52,463 Task was destroyed but it is pending! Jun 19 05:00:52 Mycodo-LIVE python[475]: task: <Task pending name='Task-424903' coro=<Client._receiver() running at /var/mycodo-root/env/lib/python3.9/site-packages/aio_msgpack_rpc/client.py:47> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7ed8b54d30>()]>> Jun 19 05:00:52 Mycodo-LIVE python[475]: 2023-06-19 05:00:52,464 Task was destroyed but it is pending! Jun 19 05:00:52 Mycodo-LIVE python[475]: task: <Task pending name='Task-424918' coro=<Client._receiver() running at /var/mycodo-root/env/lib/python3.9/site-packages/aio_msgpack_rpc/client.py:47> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7ed8a51880>()]>> Jun 19 05:00:52 Mycodo-LIVE python[475]: 2023-06-19 05:00:52,464 Task was destroyed but it is pending! Jun 19 05:00:52 Mycodo-LIVE python[475]: task: <Task pending name='Task-424919' coro=<Client._receiver() running at /var/mycodo-root/env/lib/python3.9/site-packages/aio_msgpack_rpc/client.py:47> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7ed888f280>()]>> Jun 19 05:00:52 Mycodo-LIVE python[475]: 2023-06-19 05:00:52,505 ending receiver Jun 19 05:00:52 Mycodo-LIVE python[475]: 2023-06-19 05:00:52,507 ending receiver Jun 19 05:00:52 Mycodo-LIVE python[475]: 2023-06-19 05:00:52,528 ending receiver Jun 19 05:00:54 Mycodo-LIVE python[475]: 2023-06-19 05:00:54,137 Reached max_close_wait (300.0 seconds) waiting for batches to finish writing. Force closing Jun 19 05:00:55 Mycodo-LIVE python[475]: 2023-06-19 05:00:55,683 Reached max_close_wait (300.0 seconds) waiting for batches to finish writing. Force closing Jun 19 05:00:57 Mycodo-LIVE python[475]: 2023-06-19 05:00:57,160 The retriable error occurred during request. Reason: 'HTTPConnectionPool(host='localhost', port=8086): Read timed out. (read timeout=4.992912221001461)'. Jun 19 05:00:59 Mycodo-LIVE python[475]: 2023-06-19 05:00:59,791 Task was destroyed but it is pending! Jun 19 05:01:00 Mycodo-LIVE python[475]: task: <Task pending name='Task-424858' coro=<Client._receiver() running at /var/mycodo-root/env/lib/python3.9/site-packages/aio_msgpack_rpc/client.py:47> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7ed8903610>()]>> Jun 19 05:01:00 Mycodo-LIVE python[475]: 2023-06-19 05:00:59,793 ending receiver Jun 19 05:01:00 Mycodo-LIVE python[475]: 2023-06-19 05:01:00,485 starting receiver Jun 19 05:01:00 Mycodo-LIVE python[475]: 2023-06-19 05:01:00,521 starting receiver Jun 19 05:01:01 Mycodo-LIVE python[475]: 2023-06-19 05:01:01,470 starting receiver Jun 19 05:01:01 Mycodo-LIVE python[475]: 2023-06-19 05:01:01,474 starting receiver Jun 19 05:01:01 Mycodo-LIVE python[475]: 2023-06-19 05:01:01,485 Reached max_close_wait (300.0 seconds) waiting for batches to finish writing. Force closing Jun 19 05:01:01 Mycodo-LIVE python[475]: 2023-06-19 05:01:01,704 Reached max_close_wait (300.0 seconds) waiting for batches to finish writing. Force closing Jun 19 05:01:02 Mycodo-LIVE python[475]: 2023-06-19 05:01:02,282 starting receiver Jun 19 05:01:02 Mycodo-LIVE python[475]: 2023-06-19 05:01:02,537 ending receiver Jun 19 05:01:02 Mycodo-LIVE python[475]: 2023-06-19 05:01:02,548 Task was destroyed but it is pending! Jun 19 05:01:02 Mycodo-LIVE python[475]: task: <Task pending name='Task-424931' coro=<Client._receiver() done, defined at /var/mycodo-root/env/lib/python3.9/site-packages/aio_msgpack_rpc/client.py:37> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7eda65f4f0>()]>> Jun 19 05:01:02 Mycodo-LIVE python[475]: 2023-06-19 05:01:02,549 ending receiver Jun 19 05:01:02 Mycodo-LIVE python[475]: 2023-06-19 05:01:02,554 Task was destroyed but it is pending! Jun 19 05:01:02 Mycodo-LIVE python[475]: task: <Task pending name='Task-424936' coro=<Client._receiver() done, defined at /var/mycodo-root/env/lib/python3.9/site-packages/aio_msgpack_rpc/client.py:37> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7f7faff730>()]>> Jun 19 05:01:02 Mycodo-LIVE python[475]: 2023-06-19 05:01:02,560 ending receiver Jun 19 05:01:02 Mycodo-LIVE python[475]: 2023-06-19 05:01:02,561 Task was destroyed but it is pending! Jun 19 05:01:02 Mycodo-LIVE python[475]: task: <Task pending name='Task-424941' coro=<Client._receiver() done, defined at /var/mycodo-root/env/lib/python3.9/site-packages/aio_msgpack_rpc/client.py:37> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7ed8ea1880>()]>> Jun 19 05:01:02 Mycodo-LIVE python[475]: 2023-06-19 05:01:02,561 ending receiver Jun 19 05:01:02 Mycodo-LIVE python[475]: 2023-06-19 05:01:02,562 Task was destroyed but it is pending! Jun 19 05:01:02 Mycodo-LIVE python[475]: task: <Task pending name='Task-424942' coro=<Client._receiver() done, defined at /var/mycodo-root/env/lib/python3.9/site-packages/aio_msgpack_rpc/client.py:37> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7ee1fc1070>()]>> Jun 19 05:01:02 Mycodo-LIVE python[475]: 2023-06-19 05:01:02,566 ending receiver Jun 19 05:01:02 Mycodo-LIVE python[475]: 2023-06-19 05:01:02,567 Task was destroyed but it is pending! Jun 19 05:01:02 Mycodo-LIVE python[475]: task: <Task pending name='Task-424952' coro=<Client._receiver() done, defined at /var/mycodo-root/env/lib/python3.9/site-packages/aio_msgpack_rpc/client.py:37> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7e92bd6070>()]>> Jun 19 05:01:02 Mycodo-LIVE python[475]: 2023-06-19 05:01:02,748 Reached max_close_wait (300.0 seconds) waiting for batches to finish writing. Force closing Jun 19 05:01:03 Mycodo-LIVE python[475]: 2023-06-19 05:01:03,072 Retrying (WritesRetry(total=4, connect=None, read=None, redirect=None, status=None)) after connection broken by 'ReadTimeoutError("HTTPConnectionPool(host='localhost', port=8086): Read timed out. (read timeout=4.992912221001461)")': /api/v2/write?org=mycodo&bucket=mycodo_db&precision=ns Jun 19 05:01:03 Mycodo-LIVE python[475]: 2023-06-19 05:01:03,853 Reached max_close_wait (300.0 seconds) waiting for batches to finish writing. Force closing Jun 19 05:01:04 Mycodo-LIVE python[475]: 2023-06-19 05:01:04,150 Reached max_close_wait (300.0 seconds) waiting for batches to finish writing. Force closing Jun 19 05:01:04 Mycodo-LIVE python[475]: 2023-06-19 05:01:04,467 Reached max_close_wait (300.0 seconds) waiting for batches to finish writing. Force closing Jun 19 05:01:05 Mycodo-LIVE python[475]: 2023-06-19 05:01:05,157 Reached max_close_wait (300.0 seconds) waiting for batches to finish writing. Force closing Jun 19 05:01:06 Mycodo-LIVE python[475]: 2023-06-19 05:01:06,532 Reached max_close_wait (300.0 seconds) waiting for batches to finish writing. Force closing Jun 19 05:01:34 Mycodo-LIVE python[475]: 2023-06-19 05:01:07,053 Reached max_close_wait (300.0 seconds) waiting for batches to finish writing. Force closing Jun 19 05:01:34 Mycodo-LIVE python[475]: 2023-06-19 05:01:08,077 The retriable error occurred during request. Reason: 'HTTPConnectionPool(host='localhost', port=8086): Read timed out. (read timeout=4.997883694013581)'. Jun 19 05:01:34 Mycodo-LIVE python[475]: 2023-06-19 05:01:08,424 Reached max_close_wait (300.0 seconds) waiting for batches to finish writing. Force closing Jun 19 05:01:34 Mycodo-LIVE python[475]: 2023-06-19 05:01:08,447 Reached max_close_wait (300.0 seconds) waiting for batches to finish writing. Force closing Jun 19 05:01:34 Mycodo-LIVE python[475]: 2023-06-19 05:01:09,833 Reached max_close_wait (300.0 seconds) waiting for batches to finish writing. Force closing Jun 19 05:01:34 Mycodo-LIVE python[475]: 2023-06-19 05:01:10,547 starting receiver Jun 19 05:01:34 Mycodo-LIVE python[475]: 2023-06-19 05:01:10,584 starting receiver Jun 19 05:01:34 Mycodo-LIVE python[475]: 2023-06-19 05:01:10,742 Reached max_close_wait (300.0 seconds) waiting for batches to finish writing. Force closing Jun 19 05:01:34 Mycodo-LIVE python[475]: 2023-06-19 05:01:11,569 starting receiver Jun 19 05:01:34 Mycodo-LIVE python[475]: 2023-06-19 05:01:11,590 starting receiver Jun 19 05:01:34 Mycodo-LIVE python[475]: 2023-06-19 05:01:11,668 Reached max_close_wait (300.0 seconds) waiting for batches to finish writing. Force closing Jun 19 05:01:34 Mycodo-LIVE python[475]: 2023-06-19 05:01:12,684 Reached max_close_wait (300.0 seconds) waiting for batches to finish writing. Force closing Jun 19 05:01:34 Mycodo-LIVE python[475]: 2023-06-19 05:01:14,775 Reached max_close_wait (300.0 seconds) waiting for batches to finish writing. Force closing Jun 19 05:01:34 Mycodo-LIVE python[475]: 2023-06-19 05:01:14,977 Reached max_close_wait (300.0 seconds) waiting for batches to finish writing. Force closing Jun 19 05:01:34 Mycodo-LIVE python[475]: 2023-06-19 05:01:16,386 Reached max_close_wait (300.0 seconds) waiting for batches to finish writing. Force closing Jun 19 05:01:34 Mycodo-LIVE python[475]: 2023-06-19 05:01:16,686 Reached max_close_wait (300.0 seconds) waiting for batches to finish writing. Force closing Jun 19 05:01:34 Mycodo-LIVE python[475]: 2023-06-19 05:01:16,794 ending receiver Jun 19 05:01:34 Mycodo-LIVE python[475]: 2023-06-19 05:01:16,798 Task was destroyed but it is pending! Jun 19 05:01:34 Mycodo-LIVE python[475]: task: <Task pending name='Task-424969' coro=<Client._receiver() done, defined at /var/mycodo-root/env/lib/python3.9/site-packages/aio_msgpack_rpc/client.py:37> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7ed8bad550>()]>> Jun 19 05:01:34 Mycodo-LIVE python[475]: 2023-06-19 05:01:16,799 ending receiver Jun 19 05:01:34 Mycodo-LIVE python[475]: 2023-06-19 05:01:16,800 Task was destroyed but it is pending! Jun 19 05:01:34 Mycodo-LIVE python[475]: task: <Task pending name='Task-424975' coro=<Client._receiver() done, defined at /var/mycodo-root/env/lib/python3.9/site-packages/aio_msgpack_rpc/client.py:37> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7ed8bad9d0>()]>> Jun 19 05:01:34 Mycodo-LIVE python[475]: 2023-06-19 05:01:17,584 Reached max_close_wait (300.0 seconds) waiting for batches to finish writing. Force closing Jun 19 05:01:34 Mycodo-LIVE python[475]: 2023-06-19 05:01:17,977 Reached max_close_wait (300.0 seconds) waiting for batches to finish writing. Force closing Jun 19 05:01:34 Mycodo-LIVE python[475]: 2023-06-19 05:01:18,146 Reached max_close_wait (300.0 seconds) waiting for batches to finish writing. Force closing Jun 19 05:01:34 Mycodo-LIVE python[475]: 2023-06-19 05:01:18,786 Retrying (WritesRetry(total=3, connect=None, read=None, redirect=None, status=None)) after connection broken by 'ReadTimeoutError("HTTPConnectionPool(host='localhost', port=8086): Read timed out. (read timeout=4.997883694013581)")': /api/v2/write?org=mycodo&bucket=mycodo_db&precision=ns Jun 19 05:01:34 Mycodo-LIVE python[475]: 2023-06-19 05:01:19,078 Reached max_close_wait (300.0 seconds) waiting for batches to finish writing. Force closing Jun 19 05:01:34 Mycodo-LIVE python[475]: 2023-06-19 05:01:19,353 Reached max_close_wait (300.0 seconds) waiting for batches to finish writing. Force closing Jun 19 05:01:34 Mycodo-LIVE python[475]: 2023-06-19 05:01:20,492 Reached max_close_wait (300.0 seconds) waiting for batches to finish writing. Force closing Jun 19 05:01:34 Mycodo-LIVE python[475]: 2023-06-19 05:01:20,499 Task was destroyed but it is pending! Jun 19 05:01:34 Mycodo-LIVE python[475]: task: <Task pending name='Task-424958' coro=<Client._receiver() running at /var/mycodo-root/env/lib/python3.9/site-packages/aio_msgpack_rpc/client.py:47> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7ed8996490>()]>> Jun 19 05:01:34 Mycodo-LIVE python[475]: 2023-06-19 05:01:20,499 ending receiver Jun 19 05:01:34 Mycodo-LIVE python[475]: 2023-06-19 05:01:20,500 Task was destroyed but it is pending! Jun 19 05:01:34 Mycodo-LIVE python[475]: task: <Task pending name='Task-424962' coro=<Client._receiver() running at /var/mycodo-root/env/lib/python3.9/site-packages/aio_msgpack_rpc/client.py:47> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7ed8996be0>()]>> Jun 19 05:01:34 Mycodo-LIVE python[475]: 2023-06-19 05:01:20,500 ending receiver Jun 19 05:01:34 Mycodo-LIVE python[475]: 2023-06-19 05:01:20,598 starting receiver Jun 19 05:01:34 Mycodo-LIVE python[475]: 2023-06-19 05:01:20,621 starting receiver Jun 19 05:01:34 Mycodo-LIVE python[475]: 2023-06-19 05:01:21,612 starting receiver Jun 19 05:01:34 Mycodo-LIVE python[475]: 2023-06-19 05:01:21,631 starting receiver Jun 19 05:01:34 Mycodo-LIVE python[475]: 2023-06-19 05:01:23,795 The retriable error occurred during request. Reason: 'HTTPConnectionPool(host='localhost', port=8086): Read timed out. (read timeout=4.99661273197853)'. Jun 19 05:01:34 Mycodo-LIVE python[475]: 2023-06-19 05:01:24,001 Reached max_close_wait (300.0 seconds) waiting for batches to finish writing. Force closing Jun 19 05:01:34 Mycodo-LIVE python[475]: 2023-06-19 05:01:25,795 Reached max_close_wait (300.0 seconds) waiting for batches to finish writing. Force closing Jun 19 05:01:34 Mycodo-LIVE python[475]: 2023-06-19 05:01:26,837 ending receiver Jun 19 05:01:34 Mycodo-LIVE python[475]: 2023-06-19 05:01:26,838 Task was destroyed but it is pending! Jun 19 05:01:35 Mycodo-LIVE python[475]: task: <Task pending name='Task-424994' coro=<Client._receiver() done, defined at /var/mycodo-root/env/lib/python3.9/site-packages/aio_msgpack_rpc/client.py:37> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7eb984b2e0>()]>> Jun 19 05:01:35 Mycodo-LIVE python[475]: 2023-06-19 05:01:26,838 ending receiver Jun 19 05:01:35 Mycodo-LIVE python[475]: 2023-06-19 05:01:26,839 Task was destroyed but it is pending! Jun 19 05:01:35 Mycodo-LIVE python[475]: task: <Task pending name='Task-425000' coro=<Client._receiver() done, defined at /var/mycodo-root/env/lib/python3.9/site-packages/aio_msgpack_rpc/client.py:37> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7ed8b1ea60>()]>> Jun 19 05:01:35 Mycodo-LIVE python[475]: 2023-06-19 05:01:27,380 Reached max_close_wait (300.0 seconds) waiting for batches to finish writing. Force closing Jun 19 05:01:35 Mycodo-LIVE python[475]: 2023-06-19 05:01:28,491 Reached max_close_wait (300.0 seconds) waiting for batches to finish writing. Force closing Jun 19 05:01:35 Mycodo-LIVE python[475]: 2023-06-19 05:01:29,710 Reached max_close_wait (300.0 seconds) waiting for batches to finish writing. Force closing Jun 19 05:01:35 Mycodo-LIVE python[475]: 2023-06-19 05:01:30,636 starting receiver Jun 19 05:01:35 Mycodo-LIVE python[475]: 2023-06-19 05:01:30,647 starting receiver Jun 19 05:01:35 Mycodo-LIVE python[475]: 2023-06-19 05:01:31,307 Reached max_close_wait (300.0 seconds) waiting for batches to finish writing. Force closing Jun 19 05:01:35 Mycodo-LIVE python[475]: 2023-06-19 05:01:31,513 Reached max_close_wait (300.0 seconds) waiting for batches to finish writing. Force closing Jun 19 05:01:35 Mycodo-LIVE python[475]: 2023-06-19 05:01:31,646 starting receiver Jun 19 05:01:35 Mycodo-LIVE python[475]: 2023-06-19 05:01:31,665 starting receiver Jun 19 05:01:35 Mycodo-LIVE python[475]: 2023-06-19 05:01:32,419 Reached max_close_wait (300.0 seconds) waiting for batches to finish writing. Force closing Jun 19 05:01:35 Mycodo-LIVE python[475]: 2023-06-19 05:01:32,525 Reached max_close_wait (300.0 seconds) waiting for batches to finish writing. Force closing Jun 19 05:01:35 Mycodo-LIVE python[475]: 2023-06-19 05:01:33,111 Reached max_close_wait (300.0 seconds) waiting for batches to finish writing. Force closing Jun 19 05:01:35 Mycodo-LIVE python[475]: 2023-06-19 05:01:33,516 Reached max_close_wait (300.0 seconds) waiting for batches to finish writing. Force closing Jun 19 05:01:35 Mycodo-LIVE python[475]: 2023-06-19 05:01:34,720 Reached max_close_wait (300.0 seconds) waiting for batches to finish writing. Force closing Jun 19 05:01:35 Mycodo-LIVE python[475]: 2023-06-19 05:01:35,392 ending receiver Jun 19 05:01:35 Mycodo-LIVE python[475]: 2023-06-19 05:01:35,393 Task was destroyed but it is pending! Jun 19 05:01:35 Mycodo-LIVE python[475]: task: <Task pending name='Task-425005' coro=<Client._receiver() done, defined at /var/mycodo-root/env/lib/python3.9/site-packages/aio_msgpack_rpc/client.py:37> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7ee1e28d90>()]>> Jun 19 05:01:35 Mycodo-LIVE python[475]: 2023-06-19 05:01:35,393 ending receiver Jun 19 05:01:35 Mycodo-LIVE python[475]: 2023-06-19 05:01:35,394 Task was destroyed but it is pending! Jun 19 05:01:35 Mycodo-LIVE python[475]: task: <Task pending name='Task-425010' coro=<Client._receiver() done, defined at /var/mycodo-root/env/lib/python3.9/site-packages/aio_msgpack_rpc/client.py:37> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7eccc886d0>()]>> Jun 19 05:01:35 Mycodo-LIVE python[475]: 2023-06-19 05:01:35,394 ending receiver Jun 19 05:01:35 Mycodo-LIVE python[475]: 2023-06-19 05:01:35,395 Task was destroyed but it is pending! Jun 19 05:01:35 Mycodo-LIVE python[475]: task: <Task pending name='Task-425016' coro=<Client._receiver() done, defined at /var/mycodo-root/env/lib/python3.9/site-packages/aio_msgpack_rpc/client.py:37> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7ee1e28040>()]>> Jun 19 05:01:35 Mycodo-LIVE python[475]: 2023-06-19 05:01:35,395 ending receiver Jun 19 05:01:35 Mycodo-LIVE python[475]: 2023-06-19 05:01:35,396 Task was destroyed but it is pending! Jun 19 05:01:35 Mycodo-LIVE python[475]: task: <Task pending name='Task-425022' coro=<Client._receiver() done, defined at /var/mycodo-root/env/lib/python3.9/site-packages/aio_msgpack_rpc/client.py:37> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7e8b67d430>()]>> Jun 19 05:01:37 Mycodo-LIVE python[475]: 2023-06-19 05:01:37,132 Reached max_close_wait (300.0 seconds) waiting for batches to finish writing. Force closing Jun 19 05:01:39 Mycodo-LIVE python[475]: 2023-06-19 05:01:38,418 Reached max_close_wait (300.0 seconds) waiting for batches to finish writing. Force closing Jun 19 05:01:40 Mycodo-LIVE python[475]: 2023-06-19 05:01:40,047 Reached max_close_wait (300.0 seconds) waiting for batches to finish writing. Force closing Jun 19 05:01:40 Mycodo-LIVE python[475]: 2023-06-19 05:01:40,670 starting receiver Jun 19 05:01:40 Mycodo-LIVE python[475]: 2023-06-19 05:01:40,687 starting receiver Jun 19 05:01:40 Mycodo-LIVE python[475]: 2023-06-19 05:01:40,706 ending receiver Jun 19 05:01:40 Mycodo-LIVE python[475]: 2023-06-19 05:01:40,707 Task was destroyed but it is pending! Jun 19 05:01:40 Mycodo-LIVE python[475]: task: <Task pending name='Task-425028' coro=<Client._receiver() done, defined at /var/mycodo-root/env/lib/python3.9/site-packages/aio_msgpack_rpc/client.py:37> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7e92accac0>()]>> Jun 19 05:01:40 Mycodo-LIVE python[475]: 2023-06-19 05:01:40,714 starting receiver Jun 19 05:01:41 Mycodo-LIVE python[475]: 2023-06-19 05:01:41,127 Task was destroyed but it is pending! Jun 19 05:01:41 Mycodo-LIVE python[475]: task: <Task pending name='Task-424982' coro=<Client._receiver() running at /var/mycodo-root/env/lib/python3.9/site-packages/aio_msgpack_rpc/client.py:47> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7ed8b85b80>()]>> Jun 19 05:01:41 Mycodo-LIVE python[475]: 2023-06-19 05:01:41,136 ending receiver Jun 19 05:01:41 Mycodo-LIVE python[475]: 2023-06-19 05:01:41,145 Task was destroyed but it is pending! Jun 19 05:01:41 Mycodo-LIVE python[475]: task: <Task pending name='Task-424990' coro=<Client._receiver() running at /var/mycodo-root/env/lib/python3.9/site-packages/aio_msgpack_rpc/client.py:47> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7ed8b85af0>()]>> Jun 19 05:01:41 Mycodo-LIVE python[475]: 2023-06-19 05:01:41,146 ending receiver Jun 19 05:01:41 Mycodo-LIVE python[475]: 2023-06-19 05:01:41,167 Task was destroyed but it is pending! Jun 19 05:01:41 Mycodo-LIVE python[475]: task: <Task pending name='Task-425034' coro=<Client._receiver() running at /var/mycodo-root/env/lib/python3.9/site-packages/aio_msgpack_rpc/client.py:47> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7ed8b5df10>()]>> Jun 19 05:01:41 Mycodo-LIVE python[475]: 2023-06-19 05:01:41,171 ending receiver Jun 19 05:01:41 Mycodo-LIVE python[475]: 2023-06-19 05:01:41,172 Task was destroyed but it is pending! Jun 19 05:01:41 Mycodo-LIVE python[475]: task: <Task pending name='Task-425042' coro=<Client._receiver() running at /var/mycodo-root/env/lib/python3.9/site-packages/aio_msgpack_rpc/client.py:47> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7ecced7c70>()]>> Jun 19 05:01:41 Mycodo-LIVE python[475]: 2023-06-19 05:01:41,172 ending receiver Jun 19 05:01:41 Mycodo-LIVE python[475]: 2023-06-19 05:01:07,198 Error raised in session_scope. Session will be rolled back: db_uri='sqlite:////home/pi/Mycodo/databases/mycodo.db', error='(sqlite3.OperationalError) database is locked Jun 19 05:01:41 Mycodo-LIVE python[475]: [SQL: SELECT function.id AS function_id, function.unique_id AS function_unique_id, function.function_type AS function_function_type, function.name AS function_name, function.position_y AS function_position_y, function.log_level_debug AS function_log_level_debug Jun 19 05:01:41 Mycodo-LIVE python[475]: FROM function Jun 19 05:01:41 Mycodo-LIVE python[475]: WHERE function.unique_id = ? Jun 19 05:01:41 Mycodo-LIVE python[475]: LIMIT ? OFFSET ?] Jun 19 05:01:41 Mycodo-LIVE python[475]: [parameters: ('a0417b2a-805d-4858-90b7-7e3f5151df7e', 1, 0)] Jun 19 05:01:41 Mycodo-LIVE python[475]: (Background on this error at: https://sqlalche.me/e/20/e3q8)' Jun 19 05:01:41 Mycodo-LIVE python[475]: Traceback (most recent call last): Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1964, in _exec_single_context Jun 19 05:01:41 Mycodo-LIVE python[475]: self.dialect.do_execute( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/default.py", line 748, in do_execute Jun 19 05:01:41 Mycodo-LIVE python[475]: cursor.execute(statement, parameters) Jun 19 05:01:41 Mycodo-LIVE python[475]: sqlite3.OperationalError: database is locked Jun 19 05:01:41 Mycodo-LIVE python[475]: The above exception was the direct cause of the following exception: Jun 19 05:01:41 Mycodo-LIVE python[475]: Traceback (most recent call last): Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/mycodo/databases/utils.py", line 26, in session_scope Jun 19 05:01:41 Mycodo-LIVE python[475]: yield session Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/mycodo/actions/base_action.py", line 100, in setup_logger Jun 19 05:01:41 Mycodo-LIVE python[475]: function = new_session.query(Function).filter( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/query.py", line 2752, in first Jun 19 05:01:41 Mycodo-LIVE python[475]: return self.limit(1)._iter().first() # type: ignore Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/query.py", line 2855, in _iter Jun 19 05:01:41 Mycodo-LIVE python[475]: result: Union[ScalarResult[_T], Result[_T]] = self.session.execute( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/session.py", line 2229, in execute Jun 19 05:01:41 Mycodo-LIVE python[475]: return self._execute_internal( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/session.py", line 2124, in _execute_internal Jun 19 05:01:41 Mycodo-LIVE python[475]: result: Result[Any] = compile_state_cls.orm_execute_statement( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/context.py", line 253, in orm_execute_statement Jun 19 05:01:41 Mycodo-LIVE python[475]: result = conn.execute( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1414, in execute Jun 19 05:01:41 Mycodo-LIVE python[475]: return meth( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/sql/elements.py", line 486, in _execute_on_connection Jun 19 05:01:41 Mycodo-LIVE python[475]: return connection._execute_clauseelement( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1638, in _execute_clauseelement Jun 19 05:01:41 Mycodo-LIVE python[475]: ret = self._execute_context( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1842, in _execute_context Jun 19 05:01:41 Mycodo-LIVE python[475]: return self._exec_single_context( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1983, in _exec_single_context Jun 19 05:01:41 Mycodo-LIVE python[475]: self._handle_dbapi_exception( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 2326, in _handle_dbapi_exception Jun 19 05:01:41 Mycodo-LIVE python[475]: raise sqlalchemy_exception.with_traceback(exc_info[2]) from e Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1964, in _exec_single_context Jun 19 05:01:41 Mycodo-LIVE python[475]: self.dialect.do_execute( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/default.py", line 748, in do_execute Jun 19 05:01:41 Mycodo-LIVE python[475]: cursor.execute(statement, parameters) Jun 19 05:01:41 Mycodo-LIVE python[475]: sqlalchemy.exc.OperationalError: (sqlite3.OperationalError) database is locked Jun 19 05:01:41 Mycodo-LIVE python[475]: [SQL: SELECT function.id AS function_id, function.unique_id AS function_unique_id, function.function_type AS function_function_type, function.name AS function_name, function.position_y AS function_position_y, function.log_level_debug AS function_log_level_debug Jun 19 05:01:41 Mycodo-LIVE python[475]: FROM function Jun 19 05:01:41 Mycodo-LIVE python[475]: WHERE function.unique_id = ? Jun 19 05:01:41 Mycodo-LIVE python[475]: LIMIT ? OFFSET ?] Jun 19 05:01:41 Mycodo-LIVE python[475]: [parameters: ('a0417b2a-805d-4858-90b7-7e3f5151df7e', 1, 0)] Jun 19 05:01:41 Mycodo-LIVE python[475]: (Background on this error at: https://sqlalche.me/e/20/e3q8) Jun 19 05:01:41 Mycodo-LIVE python[475]: 2023-06-19 05:01:07,539 Error raised in session_scope. Session will be rolled back: db_uri='sqlite:////home/pi/Mycodo/databases/mycodo.db', error='(sqlite3.OperationalError) database is locked Jun 19 05:01:41 Mycodo-LIVE python[475]: [SQL: SELECT function_actions.id AS function_actions_id, function_actions.unique_id AS function_actions_unique_id, function_actions.function_id AS function_actions_function_id, function_actions.function_type AS function_actions_function_type, function_actions.action_type AS function_actions_action_type, function_actions.custom_options AS function_actions_custom_options, function_actions.pause_duration AS function_actions_pause_duration, function_actions.do_unique_id AS function_actions_do_unique_id, function_actions.do_action_string AS function_actions_do_action_string, function_actions.do_output_state AS function_actions_do_output_state, function_actions.do_output_amount AS function_actions_do_output_amount, function_actions.do_output_duration AS function_actions_do_output_duration, function_actions.do_output_pwm AS function_actions_do_output_pwm, function_actions.do_output_pwm2 AS function_actions_do_output_pwm2, function_actions.do_camera_duration AS function_actions_do_camera_duration, function_actions.remote AS function_actions_remote, function_actions.code AS function_actions_code, function_actions.send_times AS function_actions_send_times Jun 19 05:01:41 Mycodo-LIVE python[475]: FROM function_actions Jun 19 05:01:41 Mycodo-LIVE python[475]: WHERE (function_actions.unique_id LIKE ? || '%') Jun 19 05:01:41 Mycodo-LIVE python[475]: LIMIT ? OFFSET ?] Jun 19 05:01:41 Mycodo-LIVE python[475]: [parameters: ('1a811689', 1, 0)] Jun 19 05:01:41 Mycodo-LIVE python[475]: (Background on this error at: https://sqlalche.me/e/20/e3q8)' Jun 19 05:01:41 Mycodo-LIVE python[475]: Traceback (most recent call last): Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1964, in _exec_single_context Jun 19 05:01:41 Mycodo-LIVE python[475]: self.dialect.do_execute( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/default.py", line 748, in do_execute Jun 19 05:01:41 Mycodo-LIVE python[475]: cursor.execute(statement, parameters) Jun 19 05:01:41 Mycodo-LIVE python[475]: sqlite3.OperationalError: database is locked Jun 19 05:01:41 Mycodo-LIVE python[475]: The above exception was the direct cause of the following exception: Jun 19 05:01:41 Mycodo-LIVE python[475]: Traceback (most recent call last): Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/mycodo/databases/utils.py", line 26, in session_scope Jun 19 05:01:41 Mycodo-LIVE python[475]: yield session Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/mycodo/controllers/base_conditional.py", line 46, in run_action Jun 19 05:01:41 Mycodo-LIVE python[475]: action = new_session.query(Actions).filter( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/query.py", line 2752, in first Jun 19 05:01:41 Mycodo-LIVE python[475]: return self.limit(1)._iter().first() # type: ignore Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/query.py", line 2855, in _iter Jun 19 05:01:41 Mycodo-LIVE python[475]: result: Union[ScalarResult[_T], Result[_T]] = self.session.execute( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/session.py", line 2229, in execute Jun 19 05:01:41 Mycodo-LIVE python[475]: return self._execute_internal( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/session.py", line 2124, in _execute_internal Jun 19 05:01:41 Mycodo-LIVE python[475]: result: Result[Any] = compile_state_cls.orm_execute_statement( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/context.py", line 253, in orm_execute_statement Jun 19 05:01:41 Mycodo-LIVE python[475]: result = conn.execute( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1414, in execute Jun 19 05:01:41 Mycodo-LIVE python[475]: return meth( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/sql/elements.py", line 486, in _execute_on_connection Jun 19 05:01:41 Mycodo-LIVE python[475]: return connection._execute_clauseelement( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1638, in _execute_clauseelement Jun 19 05:01:41 Mycodo-LIVE python[475]: ret = self._execute_context( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1842, in _execute_context Jun 19 05:01:41 Mycodo-LIVE python[475]: return self._exec_single_context( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1983, in _exec_single_context Jun 19 05:01:41 Mycodo-LIVE python[475]: self._handle_dbapi_exception( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 2326, in _handle_dbapi_exception Jun 19 05:01:41 Mycodo-LIVE python[475]: raise sqlalchemy_exception.with_traceback(exc_info[2]) from e Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1964, in _exec_single_context Jun 19 05:01:41 Mycodo-LIVE python[475]: self.dialect.do_execute( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/default.py", line 748, in do_execute Jun 19 05:01:41 Mycodo-LIVE python[475]: cursor.execute(statement, parameters) Jun 19 05:01:41 Mycodo-LIVE python[475]: sqlalchemy.exc.OperationalError: (sqlite3.OperationalError) database is locked Jun 19 05:01:41 Mycodo-LIVE python[475]: [SQL: SELECT function_actions.id AS function_actions_id, function_actions.unique_id AS function_actions_unique_id, function_actions.function_id AS function_actions_function_id, function_actions.function_type AS function_actions_function_type, function_actions.action_type AS function_actions_action_type, function_actions.custom_options AS function_actions_custom_options, function_actions.pause_duration AS function_actions_pause_duration, function_actions.do_unique_id AS function_actions_do_unique_id, function_actions.do_action_string AS function_actions_do_action_string, function_actions.do_output_state AS function_actions_do_output_state, function_actions.do_output_amount AS function_actions_do_output_amount, function_actions.do_output_duration AS function_actions_do_output_duration, function_actions.do_output_pwm AS function_actions_do_output_pwm, function_actions.do_output_pwm2 AS function_actions_do_output_pwm2, function_actions.do_camera_duration AS function_actions_do_camera_duration, function_actions.remote AS function_actions_remote, function_actions.code AS function_actions_code, function_actions.send_times AS function_actions_send_times Jun 19 05:01:41 Mycodo-LIVE python[475]: FROM function_actions Jun 19 05:01:41 Mycodo-LIVE python[475]: WHERE (function_actions.unique_id LIKE ? || '%') Jun 19 05:01:41 Mycodo-LIVE python[475]: LIMIT ? OFFSET ?] Jun 19 05:01:41 Mycodo-LIVE python[475]: [parameters: ('1a811689', 1, 0)] Jun 19 05:01:41 Mycodo-LIVE python[475]: (Background on this error at: https://sqlalche.me/e/20/e3q8) Jun 19 05:01:41 Mycodo-LIVE python[475]: Traceback (most recent call last): Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1964, in _exec_single_context Jun 19 05:01:41 Mycodo-LIVE python[475]: self.dialect.do_execute( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/default.py", line 748, in do_execute Jun 19 05:01:41 Mycodo-LIVE python[475]: cursor.execute(statement, parameters) Jun 19 05:01:41 Mycodo-LIVE python[475]: sqlite3.OperationalError: database is locked Jun 19 05:01:41 Mycodo-LIVE python[475]: The above exception was the direct cause of the following exception: Jun 19 05:01:41 Mycodo-LIVE python[475]: Traceback (most recent call last): Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/mycodo/utils/actions.py", line 332, in trigger_action Jun 19 05:01:41 Mycodo-LIVE python[475]: run_function_action = action_loaded.ActionModule(action) Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/home/pi/Mycodo/mycodo/actions/mqtt_publish.py", line 134, in init Jun 19 05:01:41 Mycodo-LIVE python[475]: super().init(action_dev, testing=testing, name=name) Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/mycodo/actions/base_action.py", line 42, in init Jun 19 05:01:41 Mycodo-LIVE python[475]: self.setup_logger(testing=testing, name=name, action=action_dev) Jun 19 05:01:41 Mycodo-LIVE python[475]: 2023-06-19 05:01:07,557 Error raised in session_scope. Session will be rolled back: db_uri='sqlite:////home/pi/Mycodo/databases/mycodo.db', error='(sqlite3.OperationalError) database is locked Jun 19 05:01:41 Mycodo-LIVE python[475]: [SQL: SELECT function_actions.id AS function_actions_id, function_actions.unique_id AS function_actions_unique_id, function_actions.function_id AS function_actions_function_id, function_actions.function_type AS function_actions_function_type, function_actions.action_type AS function_actions_action_type, function_actions.custom_options AS function_actions_custom_options, function_actions.pause_duration AS function_actions_pause_duration, function_actions.do_unique_id AS function_actions_do_unique_id, function_actions.do_action_string AS function_actions_do_action_string, function_actions.do_output_state AS function_actions_do_output_state, function_actions.do_output_amount AS function_actions_do_output_amount, function_actions.do_output_duration AS function_actions_do_output_duration, function_actions.do_output_pwm AS function_actions_do_output_pwm, function_actions.do_output_pwm2 AS function_actions_do_output_pwm2, function_actions.do_camera_duration AS function_actions_do_camera_duration, function_actions.remote AS function_actions_remote, function_actions.code AS function_actions_code, function_actions.send_times AS function_actions_send_times Jun 19 05:01:41 Mycodo-LIVE python[475]: FROM function_actions Jun 19 05:01:41 Mycodo-LIVE python[475]: WHERE (function_actions.unique_id LIKE ? || '%') Jun 19 05:01:41 Mycodo-LIVE python[475]: LIMIT ? OFFSET ?] Jun 19 05:01:41 Mycodo-LIVE python[475]: [parameters: ('9c798bf5', 1, 0)] Jun 19 05:01:41 Mycodo-LIVE python[475]: (Background on this error at: https://sqlalche.me/e/20/e3q8)' Jun 19 05:01:41 Mycodo-LIVE python[475]: Traceback (most recent call last): Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1964, in _exec_single_context Jun 19 05:01:41 Mycodo-LIVE python[475]: self.dialect.do_execute( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/default.py", line 748, in do_execute Jun 19 05:01:41 Mycodo-LIVE python[475]: cursor.execute(statement, parameters) Jun 19 05:01:41 Mycodo-LIVE python[475]: sqlite3.OperationalError: database is locked Jun 19 05:01:41 Mycodo-LIVE python[475]: The above exception was the direct cause of the following exception: Jun 19 05:01:41 Mycodo-LIVE python[475]: Traceback (most recent call last): Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/mycodo/databases/utils.py", line 26, in session_scope Jun 19 05:01:41 Mycodo-LIVE python[475]: yield session Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/mycodo/controllers/base_conditional.py", line 46, in run_action Jun 19 05:01:41 Mycodo-LIVE python[475]: action = new_session.query(Actions).filter( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/query.py", line 2752, in first Jun 19 05:01:41 Mycodo-LIVE python[475]: return self.limit(1)._iter().first() # type: ignore Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/query.py", line 2855, in _iter Jun 19 05:01:41 Mycodo-LIVE python[475]: result: Union[ScalarResult[_T], Result[_T]] = self.session.execute( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/session.py", line 2229, in execute Jun 19 05:01:41 Mycodo-LIVE python[475]: return self._execute_internal( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/session.py", line 2124, in _execute_internal Jun 19 05:01:41 Mycodo-LIVE python[475]: result: Result[Any] = compile_state_cls.orm_execute_statement( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/context.py", line 253, in orm_execute_statement Jun 19 05:01:41 Mycodo-LIVE python[475]: result = conn.execute( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1414, in execute Jun 19 05:01:41 Mycodo-LIVE python[475]: return meth( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/sql/elements.py", line 486, in _execute_on_connection Jun 19 05:01:41 Mycodo-LIVE python[475]: return connection._execute_clauseelement( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1638, in _execute_clauseelement Jun 19 05:01:41 Mycodo-LIVE python[475]: ret = self._execute_context( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1842, in _execute_context Jun 19 05:01:41 Mycodo-LIVE python[475]: return self._exec_single_context( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1983, in _exec_single_context Jun 19 05:01:41 Mycodo-LIVE python[475]: self._handle_dbapi_exception( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 2326, in _handle_dbapi_exception Jun 19 05:01:41 Mycodo-LIVE python[475]: raise sqlalchemy_exception.with_traceback(exc_info[2]) from e Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1964, in _exec_single_context Jun 19 05:01:41 Mycodo-LIVE python[475]: self.dialect.do_execute( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/default.py", line 748, in do_execute Jun 19 05:01:41 Mycodo-LIVE python[475]: cursor.execute(statement, parameters) Jun 19 05:01:41 Mycodo-LIVE python[475]: sqlalchemy.exc.OperationalError: (sqlite3.OperationalError) database is locked Jun 19 05:01:41 Mycodo-LIVE python[475]: [SQL: SELECT function_actions.id AS function_actions_id, function_actions.unique_id AS function_actions_unique_id, function_actions.function_id AS function_actions_function_id, function_actions.function_type AS function_actions_function_type, function_actions.action_type AS function_actions_action_type, function_actions.custom_options AS function_actions_custom_options, function_actions.pause_duration AS function_actions_pause_duration, function_actions.do_unique_id AS function_actions_do_unique_id, function_actions.do_action_string AS function_actions_do_action_string, function_actions.do_output_state AS function_actions_do_output_state, function_actions.do_output_amount AS function_actions_do_output_amount, function_actions.do_output_duration AS function_actions_do_output_duration, function_actions.do_output_pwm AS function_actions_do_output_pwm, function_actions.do_output_pwm2 AS function_actions_do_output_pwm2, function_actions.do_camera_duration AS function_actions_do_camera_duration, function_actions.remote AS function_actions_remote, function_actions.code AS function_actions_code, function_actions.send_times AS function_actions_send_times Jun 19 05:01:41 Mycodo-LIVE python[475]: FROM function_actions Jun 19 05:01:41 Mycodo-LIVE python[475]: WHERE (function_actions.unique_id LIKE ? || '%') Jun 19 05:01:41 Mycodo-LIVE python[475]: LIMIT ? OFFSET ?] Jun 19 05:01:41 Mycodo-LIVE python[475]: [parameters: ('9c798bf5', 1, 0)] Jun 19 05:01:41 Mycodo-LIVE python[475]: (Background on this error at: https://sqlalche.me/e/20/e3q8) Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/mycodo/actions/base_action.py", line 100, in setup_logger Jun 19 05:01:41 Mycodo-LIVE python[475]: function = new_session.query(Function).filter( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/query.py", line 2752, in first Jun 19 05:01:41 Mycodo-LIVE python[475]: return self.limit(1)._iter().first() # type: ignore Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/query.py", line 2855, in _iter Jun 19 05:01:41 Mycodo-LIVE python[475]: result: Union[ScalarResult[_T], Result[_T]] = self.session.execute( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/session.py", line 2229, in execute Jun 19 05:01:41 Mycodo-LIVE python[475]: return self._execute_internal( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/session.py", line 2124, in _execute_internal Jun 19 05:01:41 Mycodo-LIVE python[475]: result: Result[Any] = compile_state_cls.orm_execute_statement( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/context.py", line 253, in orm_execute_statement Jun 19 05:01:41 Mycodo-LIVE python[475]: result = conn.execute( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1414, in execute Jun 19 05:01:41 Mycodo-LIVE python[475]: return meth( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/sql/elements.py", line 486, in _execute_on_connection Jun 19 05:01:41 Mycodo-LIVE python[475]: return connection._execute_clauseelement( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1638, in _execute_clauseelement Jun 19 05:01:41 Mycodo-LIVE python[475]: ret = self._execute_context( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1842, in _execute_context Jun 19 05:01:41 Mycodo-LIVE python[475]: return self._exec_single_context( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1983, in _exec_single_context Jun 19 05:01:41 Mycodo-LIVE python[475]: self._handle_dbapi_exception( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 2326, in _handle_dbapi_exception Jun 19 05:01:41 Mycodo-LIVE python[475]: raise sqlalchemy_exception.with_traceback(exc_info[2]) from e Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1964, in _exec_single_context Jun 19 05:01:41 Mycodo-LIVE python[475]: self.dialect.do_execute( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/default.py", line 748, in do_execute Jun 19 05:01:41 Mycodo-LIVE python[475]: cursor.execute(statement, parameters) Jun 19 05:01:41 Mycodo-LIVE python[475]: sqlalchemy.exc.OperationalError: (sqlite3.OperationalError) database is locked Jun 19 05:01:41 Mycodo-LIVE python[475]: [SQL: SELECT function.id AS function_id, function.unique_id AS function_unique_id, function.function_type AS function_function_type, function.name AS function_name, function.position_y AS function_position_y, function.log_level_debug AS function_log_level_debug Jun 19 05:01:41 Mycodo-LIVE python[475]: FROM function Jun 19 05:01:41 Mycodo-LIVE python[475]: WHERE function.unique_id = ? Jun 19 05:01:41 Mycodo-LIVE python[475]: LIMIT ? OFFSET ?] Jun 19 05:01:41 Mycodo-LIVE python[475]: [parameters: ('a0417b2a-805d-4858-90b7-7e3f5151df7e', 1, 0)] Jun 19 05:01:41 Mycodo-LIVE python[475]: (Background on this error at: https://sqlalche.me/e/20/e3q8) Jun 19 05:01:41 Mycodo-LIVE python[475]: 2023-06-19 05:01:07,590 Error raised in session_scope. Session will be rolled back: db_uri='sqlite:////home/pi/Mycodo/databases/mycodo.db', error='(sqlite3.OperationalError) database is locked Jun 19 05:01:41 Mycodo-LIVE python[475]: [SQL: SELECT misc.id AS misc_id, misc.dismiss_notification AS misc_dismiss_notification, misc.force_https AS misc_force_https, misc.hide_alert_info AS misc_hide_alert_info, misc.hide_alert_success AS misc_hide_alert_success, misc.hide_alert_warning AS misc_hide_alert_warning, misc.hide_tooltips AS misc_hide_tooltips, misc.grid_cell_height AS misc_grid_cell_height, misc.login_message AS misc_login_message, misc.max_amps AS misc_max_amps, misc.output_usage_cost AS misc_output_usage_cost, misc.output_usage_currency AS misc_output_usage_currency, misc.output_usage_dayofmonth AS misc_output_usage_dayofmonth, misc.output_usage_volts AS misc_output_usage_volts, misc.output_usage_report_gen AS misc_output_usage_report_gen, misc.output_usage_report_span AS misc_output_usage_report_span, misc.output_usage_report_day AS misc_output_usage_report_day, misc.output_usage_report_hour AS misc_output_usage_report_hour, misc.sample_rate_controller_conditional AS misc_sample_rate_controller_conditional, misc.sample_rate_controller_function AS misc_sample_rate_controller_function, misc.sample_rate_controller_input AS misc_sample_rate_controller_input, misc.sample_rate_controller_math AS misc_sample_rate_controller_math, misc.sample_rate_controller_output AS misc_sample_rate_controller_output, misc.sample_rate_controller_pid AS misc_sample_rate_controller_pid, misc.sample_rate_controller_widget AS misc_sample_rate_controller_widget, misc.stats_opt_out AS misc_stats_opt_out, misc.enable_upgrade_check AS misc_enable_upgrade_check, misc.mycodo_upgrade_available AS misc_mycodo_upgrade_available, misc.rpyc_timeout AS misc_rpyc_timeout, misc.daemon_debug_mode AS misc_daemon_debug_mode, misc.net_test_ip AS misc_net_test_ip, misc.net_test_port AS misc_net_test_port, misc.net_test_timeout AS misc_net_test_timeout, misc.default_login_page AS misc_default_login_page, misc.measurement_db_retention_policy AS misc_measurement_db_retention_policy, misc.measurement_db_name AS misc_measurement_db_name, misc.measurement_db_version AS misc_measurement_db_version, misc.measurement_db_host AS misc_measurement_db_host, misc.measurement_db_port AS misc_measurement_db_port, misc.measurement_db_user AS misc_measurement_db_user, misc.measurement_db_password AS misc_measurement_db_password, misc.measurement_db_dbname AS misc_measurement_db_dbname Jun 19 05:01:41 Mycodo-LIVE python[475]: FROM misc Jun 19 05:01:41 Mycodo-LIVE python[475]: LIMIT ? OFFSET ?] Jun 19 05:01:41 Mycodo-LIVE python[475]: [parameters: (1, 0)] Jun 19 05:01:41 Mycodo-LIVE python[475]: (Background on this error at: https://sqlalche.me/e/20/e3q8)' Jun 19 05:01:41 Mycodo-LIVE python[475]: Traceback (most recent call last): Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1964, in _exec_single_context Jun 19 05:01:41 Mycodo-LIVE python[475]: self.dialect.do_execute( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/default.py", line 748, in do_execute Jun 19 05:01:41 Mycodo-LIVE python[475]: cursor.execute(statement, parameters) Jun 19 05:01:41 Mycodo-LIVE python[475]: sqlite3.OperationalError: database is locked Jun 19 05:01:41 Mycodo-LIVE python[475]: The above exception was the direct cause of the following exception: Jun 19 05:01:41 Mycodo-LIVE python[475]: Traceback (most recent call last): Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/mycodo/databases/utils.py", line 26, in session_scope Jun 19 05:01:41 Mycodo-LIVE python[475]: yield session Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/mycodo/utils/database.py", line 70, in db_retrieve_table_daemon Jun 19 05:01:41 Mycodo-LIVE python[475]: return_table = return_table.first() Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/query.py", line 2752, in first Jun 19 05:01:41 Mycodo-LIVE python[475]: return self.limit(1)._iter().first() # type: ignore Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/query.py", line 2855, in _iter Jun 19 05:01:41 Mycodo-LIVE python[475]: result: Union[ScalarResult[_T], Result[_T]] = self.session.execute( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/session.py", line 2229, in execute Jun 19 05:01:41 Mycodo-LIVE python[475]: return self._execute_internal( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/session.py", line 2124, in _execute_internal Jun 19 05:01:41 Mycodo-LIVE python[475]: result: Result[Any] = compile_state_cls.orm_execute_statement( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/context.py", line 253, in orm_execute_statement Jun 19 05:01:41 Mycodo-LIVE python[475]: result = conn.execute( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1414, in execute Jun 19 05:01:41 Mycodo-LIVE python[475]: return meth( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/sql/elements.py", line 486, in _execute_on_connection Jun 19 05:01:41 Mycodo-LIVE python[475]: return connection._execute_clauseelement( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1638, in _execute_clauseelement Jun 19 05:01:41 Mycodo-LIVE python[475]: ret = self._execute_context( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1842, in _execute_context Jun 19 05:01:41 Mycodo-LIVE python[475]: return self._exec_single_context( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1983, in _exec_single_context Jun 19 05:01:41 Mycodo-LIVE python[475]: self._handle_dbapi_exception( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 2326, in _handle_dbapi_exception Jun 19 05:01:41 Mycodo-LIVE python[475]: raise sqlalchemy_exception.with_traceback(exc_info[2]) from e Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1964, in _exec_single_context Jun 19 05:01:41 Mycodo-LIVE python[475]: self.dialect.do_execute( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/default.py", line 748, in do_execute Jun 19 05:01:41 Mycodo-LIVE python[475]: cursor.execute(statement, parameters) Jun 19 05:01:41 Mycodo-LIVE python[475]: sqlalchemy.exc.OperationalError: (sqlite3.OperationalError) database is locked Jun 19 05:01:41 Mycodo-LIVE python[475]: [SQL: SELECT misc.id AS misc_id, misc.dismiss_notification AS misc_dismiss_notification, misc.force_https AS misc_force_https, misc.hide_alert_info AS misc_hide_alert_info, misc.hide_alert_success AS misc_hide_alert_success, misc.hide_alert_warning AS misc_hide_alert_warning, misc.hide_tooltips AS misc_hide_tooltips, misc.grid_cell_height AS misc_grid_cell_height, misc.login_message AS misc_login_message, misc.max_amps AS misc_max_amps, misc.output_usage_cost AS misc_output_usage_cost, misc.output_usage_currency AS misc_output_usage_currency, misc.output_usage_dayofmonth AS misc_output_usage_dayofmonth, misc.output_usage_volts AS misc_output_usage_volts, misc.output_usage_report_gen AS misc_output_usage_report_gen, misc.output_usage_report_span AS misc_output_usage_report_span, misc.output_usage_report_day AS misc_output_usage_report_day, misc.output_usage_report_hour AS misc_output_usage_report_hour, misc.sample_rate_controller_conditional AS misc_sample_rate_controller_conditional, misc.sample_rate_controller_function AS misc_sample_rate_controller_function, misc.sample_rate_controller_input AS misc_sample_rate_controller_input, misc.sample_rate_controller_math AS misc_sample_rate_controller_math, misc.sample_rate_controller_output AS misc_sample_rate_controller_output, misc.sample_rate_controller_pid AS misc_sample_rate_controller_pid, misc.sample_rate_controller_widget AS misc_sample_rate_controller_widget, misc.stats_opt_out AS misc_stats_opt_out, misc.enable_upgrade_check AS misc_enable_upgrade_check, misc.mycodo_upgrade_available AS misc_mycodo_upgrade_available, misc.rpyc_timeout AS misc_rpyc_timeout, misc.daemon_debug_mode AS misc_daemon_debug_mode, misc.net_test_ip AS misc_net_test_ip, misc.net_test_port AS misc_net_test_port, misc.net_test_timeout AS misc_net_test_timeout, misc.default_login_page AS misc_default_login_page, misc.measurement_db_retention_policy AS misc_measurement_db_retention_policy, misc.measurement_db_name AS misc_measurement_db_name, misc.measurement_db_version AS misc_measurement_db_version, misc.measurement_db_host AS misc_measurement_db_host, misc.measurement_db_port AS misc_measurement_db_port, misc.measurement_db_user AS misc_measurement_db_user, misc.measurement_db_password AS misc_measurement_db_password, misc.measurement_db_dbname AS misc_measurement_db_dbname Jun 19 05:01:41 Mycodo-LIVE python[475]: FROM misc Jun 19 05:01:41 Mycodo-LIVE python[475]: LIMIT ? OFFSET ?] Jun 19 05:01:41 Mycodo-LIVE python[475]: [parameters: (1, 0)] Jun 19 05:01:41 Mycodo-LIVE python[475]: (Background on this error at: https://sqlalche.me/e/20/e3q8) Jun 19 05:01:41 Mycodo-LIVE python[475]: 2023-06-19 05:01:07,687 loop() Error Jun 19 05:01:41 Mycodo-LIVE python[475]: Traceback (most recent call last): Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1964, in _exec_single_context Jun 19 05:01:41 Mycodo-LIVE python[475]: self.dialect.do_execute( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/default.py", line 748, in do_execute Jun 19 05:01:41 Mycodo-LIVE python[475]: cursor.execute(statement, parameters) Jun 19 05:01:41 Mycodo-LIVE python[475]: sqlite3.OperationalError: database is locked Jun 19 05:01:41 Mycodo-LIVE python[475]: The above exception was the direct cause of the following exception: Jun 19 05:01:41 Mycodo-LIVE python[475]: Traceback (most recent call last): Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/mycodo/controllers/base_controller.py", line 81, in run Jun 19 05:01:41 Mycodo-LIVE python[475]: self.loop() Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/mycodo/controllers/controller_input.py", line 220, in loop Jun 19 05:01:41 Mycodo-LIVE python[475]: measurements_dict = self.create_measurements_dict() Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/mycodo/controllers/controller_input.py", line 418, in create_measurements_dict Jun 19 05:01:41 Mycodo-LIVE python[475]: measurement = self.device_measurements.filter( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/query.py", line 2752, in first Jun 19 05:01:41 Mycodo-LIVE python[475]: return self.limit(1)._iter().first() # type: ignore Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/query.py", line 2855, in _iter Jun 19 05:01:41 Mycodo-LIVE python[475]: result: Union[ScalarResult[_T], Result[_T]] = self.session.execute( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/session.py", line 2229, in execute Jun 19 05:01:41 Mycodo-LIVE python[475]: return self._execute_internal( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/session.py", line 2124, in _execute_internal Jun 19 05:01:41 Mycodo-LIVE python[475]: result: Result[Any] = compile_state_cls.orm_execute_statement( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/context.py", line 253, in orm_execute_statement Jun 19 05:01:41 Mycodo-LIVE python[475]: result = conn.execute( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1414, in execute Jun 19 05:01:41 Mycodo-LIVE python[475]: return meth( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/sql/elements.py", line 486, in _execute_on_connection Jun 19 05:01:41 Mycodo-LIVE python[475]: return connection._execute_clauseelement( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1638, in _execute_clauseelement Jun 19 05:01:41 Mycodo-LIVE python[475]: ret = self._execute_context( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1842, in _execute_context Jun 19 05:01:41 Mycodo-LIVE python[475]: return self._exec_single_context( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1983, in _exec_single_context Jun 19 05:01:41 Mycodo-LIVE python[475]: self._handle_dbapi_exception( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 2326, in _handle_dbapi_exception Jun 19 05:01:41 Mycodo-LIVE python[475]: raise sqlalchemy_exception.with_traceback(exc_info[2]) from e Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1964, in _exec_single_context Jun 19 05:01:41 Mycodo-LIVE python[475]: self.dialect.do_execute( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/default.py", line 748, in do_execute Jun 19 05:01:41 Mycodo-LIVE python[475]: cursor.execute(statement, parameters) Jun 19 05:01:41 Mycodo-LIVE python[475]: sqlalchemy.exc.OperationalError: (sqlite3.OperationalError) database is locked Jun 19 05:01:41 Mycodo-LIVE python[475]: [SQL: SELECT device_measurements.id AS device_measurements_id, device_measurements.unique_id AS device_measurements_unique_id, device_measurements.name AS device_measurements_name, device_measurements.device_type AS device_measurements_device_type, device_measurements.device_id AS device_measurements_device_id, device_measurements.is_enabled AS device_measurements_is_enabled, device_measurements.measurement AS device_measurements_measurement, device_measurements.measurement_type AS device_measurements_measurement_type, device_measurements.unit AS device_measurements_unit, device_measurements.channel AS device_measurements_channel, device_measurements.rescale_method AS device_measurements_rescale_method, device_measurements.rescale_equation AS device_measurements_rescale_equation, device_measurements.invert_scale AS device_measurements_invert_scale, device_measurements.rescaled_measurement AS device_measurements_rescaled_measurement, device_measurements.rescaled_unit AS device_measurements_rescaled_unit, device_measurements.scale_from_min AS device_measurements_scale_from_min, device_measurements.scale_from_max AS device_measurements_scale_from_max, device_measurements.scale_to_min AS device_measurements_scale_to_min, device_measurements.scale_to_max AS device_measurements_scale_to_max, device_measurements.conversion_id AS device_measurements_conversion_id Jun 19 05:01:41 Mycodo-LIVE python[475]: FROM device_measurements Jun 19 05:01:41 Mycodo-LIVE python[475]: WHERE device_measurements.device_id = ? AND device_measurements.channel = ? Jun 19 05:01:41 Mycodo-LIVE python[475]: LIMIT ? OFFSET ?] Jun 19 05:01:41 Mycodo-LIVE python[475]: [parameters: ('fc05a536-9533-45fa-8cd4-3afc56ef8e25', 0, 1, 0)] Jun 19 05:01:41 Mycodo-LIVE python[475]: (Background on this error at: https://sqlalche.me/e/20/e3q8) Jun 19 05:01:41 Mycodo-LIVE python[475]: 2023-06-19 05:01:07,790 Could not check Trigger for channel 4 of output 4c46969e-de6d-4747-a582-738cea12d651: (sqlite3.OperationalError) database is locked Jun 19 05:01:41 Mycodo-LIVE python[475]: [SQL: SELECT output_channel.id AS output_channel_id, output_channel.unique_id AS output_channel_unique_id, output_channel.output_id AS output_channel_output_id, output_channel.channel AS output_channel_channel, output_channel.name AS output_channel_name, output_channel.custom_options AS output_channel_custom_options Jun 19 05:01:41 Mycodo-LIVE python[475]: FROM output_channel Jun 19 05:01:41 Mycodo-LIVE python[475]: WHERE output_channel.output_id = ? AND output_channel.channel = ? Jun 19 05:01:41 Mycodo-LIVE python[475]: LIMIT ? OFFSET ?] Jun 19 05:01:41 Mycodo-LIVE python[475]: [parameters: ('4c46969e-de6d-4747-a582-738cea12d651', 4, 1, 0)] Jun 19 05:01:41 Mycodo-LIVE python[475]: (Background on this error at: https://sqlalche.me/e/20/e3q8) Jun 19 05:01:41 Mycodo-LIVE python[475]: 2023-06-19 05:01:07,790 Exception while running loop() Jun 19 05:01:41 Mycodo-LIVE python[475]: Traceback (most recent call last): Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1964, in _exec_single_context Jun 19 05:01:41 Mycodo-LIVE python[475]: self.dialect.do_execute( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/default.py", line 748, in do_execute Jun 19 05:01:41 Mycodo-LIVE python[475]: cursor.execute(statement, parameters) Jun 19 05:01:41 Mycodo-LIVE python[475]: sqlite3.OperationalError: database is locked Jun 19 05:01:41 Mycodo-LIVE python[475]: The above exception was the direct cause of the following exception: Jun 19 05:01:41 Mycodo-LIVE python[475]: Traceback (most recent call last): Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/mycodo/controllers/controller_function.py", line 79, in loop Jun 19 05:01:41 Mycodo-LIVE python[475]: self.run_function.loop() Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/home/pi/Mycodo/mycodo/functions/vapor_pressure_deficit.py", line 166, in loop Jun 19 05:01:41 Mycodo-LIVE python[475]: last_measurement_temp = self.get_last_measurement( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/mycodo/abstract_base_controller.py", line 533, in get_last_measurement Jun 19 05:01:41 Mycodo-LIVE python[475]: return get_last_measurement(device_id, measurement_id, max_age=max_age) Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/mycodo/utils/influx.py", line 306, in get_last_measurement Jun 19 05:01:41 Mycodo-LIVE python[475]: device_measurement = db_retrieve_table_daemon( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/query.py", line 2752, in first Jun 19 05:01:41 Mycodo-LIVE python[475]: return self.limit(1)._iter().first() # type: ignore Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/query.py", line 2855, in _iter Jun 19 05:01:41 Mycodo-LIVE python[475]: result: Union[ScalarResult[_T], Result[_T]] = self.session.execute( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/session.py", line 2229, in execute Jun 19 05:01:41 Mycodo-LIVE python[475]: return self._execute_internal( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/session.py", line 2124, in _execute_internal Jun 19 05:01:41 Mycodo-LIVE python[475]: result: Result[Any] = compile_state_cls.orm_execute_statement( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/orm/context.py", line 253, in orm_execute_statement Jun 19 05:01:41 Mycodo-LIVE python[475]: result = conn.execute( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1414, in execute Jun 19 05:01:41 Mycodo-LIVE python[475]: return meth( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/sql/elements.py", line 486, in _execute_on_connection Jun 19 05:01:41 Mycodo-LIVE python[475]: return connection._execute_clauseelement( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1638, in _execute_clauseelement Jun 19 05:01:41 Mycodo-LIVE python[475]: ret = self._execute_context( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1842, in _execute_context Jun 19 05:01:41 Mycodo-LIVE python[475]: return self._exec_single_context( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1983, in _exec_single_context Jun 19 05:01:41 Mycodo-LIVE python[475]: self._handle_dbapi_exception( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 2326, in _handle_dbapi_exception Jun 19 05:01:41 Mycodo-LIVE python[475]: raise sqlalchemy_exception.with_traceback(exc_info[2]) from e Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/base.py", line 1964, in _exec_single_context Jun 19 05:01:41 Mycodo-LIVE python[475]: self.dialect.do_execute( Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/env/lib/python3.9/site-packages/sqlalchemy/engine/default.py", line 748, in do_execute Jun 19 05:01:41 Mycodo-LIVE python[475]: cursor.execute(statement, parameters) Jun 19 05:01:41 Mycodo-LIVE python[475]: sqlalchemy.exc.OperationalError: (sqlite3.OperationalError) database is locked Jun 19 05:01:41 Mycodo-LIVE python[475]: [SQL: SELECT device_measurements.id AS device_measurements_id, device_measurements.unique_id AS device_measurements_unique_id, device_measurements.name AS device_measurements_name, device_measurements.device_type AS device_measurements_device_type, device_measurements.device_id AS device_measurements_device_id, device_measurements.is_enabled AS device_measurements_is_enabled, device_measurements.measurement AS device_measurements_measurement, device_measurements.measurement_type AS device_measurements_measurement_type, device_measurements.unit AS device_measurements_unit, device_measurements.channel AS device_measurements_channel, device_measurements.rescale_method AS device_measurements_rescale_method, device_measurements.rescale_equation AS device_measurements_rescale_equation, device_measurements.invert_scale AS device_measurements_invert_scale, device_measurements.rescaled_measurement AS device_measurements_rescaled_measurement, device_measurements.rescaled_unit AS device_measurements_rescaled_unit, device_measurements.scale_from_min AS device_measurements_scale_from_min, device_measurements.scale_from_max AS device_measurements_scale_from_max, device_measurements.scale_to_min AS device_measurements_scale_to_min, device_measurements.scale_to_max AS device_measurements_scale_to_max, device_measurements.conversion_id AS device_measurements_conversion_id Jun 19 05:01:41 Mycodo-LIVE python[475]: FROM device_measurements Jun 19 05:01:41 Mycodo-LIVE python[475]: WHERE device_measurements.unique_id = ? Jun 19 05:01:41 Mycodo-LIVE python[475]: LIMIT ? OFFSET ?]

It just continues on like this for hours after that initial "database locked" error.

What are all of these messages about? They seem to be occurring more frequently up until the database gets locked? "Reached max_close_wait (300.0 seconds) waiting for batches to finish writing. Force closing"

And what are all the URL errors from.... "/var/mycodo-root/env/lib/python3.9/site-packages/urllib3/connectionpool.py:1045: InsecureRequestWarning: Unverified HTTPS request is being made to host '127.0.0.1'. Adding certificate verification is strongly advised."

Why are there HTTPS requests happening so often? Are these internal requests? These are happening while I am asleep, so it's not me trying to access the web gui.

kizniche commented 1 year ago

How am I supposed to figure that out if the log doesn't show anything?

There are several ways to view process stats in Linux. Also, if you have a specific part of a log to show, that's fine, but pasting very long segments only makes this issue more difficult to navigate and less likely to be read. If you can, go through and clean up your previous posts. If you do have long text segments that are relevant, attach it as a file.

LucidEye commented 1 year ago

But I don't know if what I am "cleaning" is possibly important information. I am pretty much guessing at what messages and errors are possibly leading to this... I was hoping you would have a better understanding of what these log entries mean.

kizniche commented 1 year ago

So pasting long swaths of logs is probably not the right approach if you don't know what's relevant, unless logs are specifically asked for. The first thing you should be doing is determining what is causing the high CPU load, then determine if that's what's causing the other ensuing system issues.

LucidEye commented 1 year ago

That's what I am trying to do, but the logs are not showing me anything that might be the cause, just that the database becomes locked for some reason. I can not access the pi when it is in this state... it is completely unresponsive. I can not access it by SSH, and I can not access the web gui.... so how do you suggest I find the process that is causing this?

kizniche commented 1 year ago

CPU usage per process is not something that is logged by default, as you can imagine because it would be an incredible resource hog, though I'm sure tools exist to do it.

LucidEye commented 1 year ago

Does this help? After the last crash I just left an ssh session open running htop so I could try to see what process kept gobbling up resources until there were none left.
It's still running ok at the moment, but this process has started to use noticeably more CPU time than the others (the one at the top of the list)...

Screenshot at 2023-06-20 17-06-10

Also, here are a couple of the locked database errors from the syslog... Am I getting warmer? Is any of this useful?

un 19 05:01:41 Mycodo-LIVE python[475]: sqlalchemy.exc.OperationalError: (sqlite3.OperationalError) database is locked Jun 19 05:01:41 Mycodo-LIVE python[475]: [SQL: SELECT function.id AS function_id, function.unique_id AS function_unique_id, function.function_type AS function_function_type, function.name AS function_name, function.position_y AS function_position_y, function.log_level_debug AS function_log_level_debug Jun 19 05:01:41 Mycodo-LIVE python[475]: FROM function Jun 19 05:01:41 Mycodo-LIVE python[475]: WHERE function.unique_id = ? Jun 19 05:01:41 Mycodo-LIVE python[475]: LIMIT ? OFFSET ?] Jun 19 05:01:41 Mycodo-LIVE python[475]: [parameters: ('a0417b2a-805d-4858-90b7-7e3f5151df7e', 1, 0)] Jun 19 05:01:41 Mycodo-LIVE python[475]: (Background on this error at: https://sqlalche.me/e/20/e3q8) Jun 19 05:01:41 Mycodo-LIVE python[475]: 2023-06-19 05:01:07,539 Error raised in session_scope. Session will be rolled back: db_uri='sqlite:////home/pi/Mycodo/databases/mycodo.db', error='(sqlite3.OperationalError) database is locked Jun 19 05:01:41 Mycodo-LIVE python[475]: [SQL: SELECT function_actions.id AS function_actions_id, function_actions.unique_id AS function_actions_unique_id, function_actions.function_id AS function_actions_function_id, function_actions.function_type AS function_actions_function_type, function_actions.action_type AS function_actions_action_type, function_actions.custom_options AS function_actions_custom_options, function_actions.pause_duration AS function_actions_pause_duration, function_actions.do_unique_id AS function_actions_do_unique_id, function_actions.do_action_string AS function_actions_do_action_string, function_actions.do_output_state AS function_actions_do_output_state, function_actions.do_output_amount AS function_actions_do_output_amount, function_actions.do_output_duration AS function_actions_do_output_duration, function_actions.do_output_pwm AS function_actions_do_output_pwm, function_actions.do_output_pwm2 AS function_actions_do_output_pwm2, function_actions.do_camera_duration AS function_actions_do_camera_duration, function_actions.remote AS function_actions_remote, function_actions.code AS function_actions_code, function_actions.send_times AS function_actions_send_times

Jun 19 05:01:41 Mycodo-LIVE python[475]: cursor.execute(statement, parameters) Jun 19 05:01:41 Mycodo-LIVE python[475]: sqlite3.OperationalError: database is locked Jun 19 05:01:41 Mycodo-LIVE python[475]: The above exception was the direct cause of the following exception: Jun 19 05:01:41 Mycodo-LIVE python[475]: Traceback (most recent call last): Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/mycodo/utils/actions.py", line 332, in trigger_action Jun 19 05:01:41 Mycodo-LIVE python[475]: run_function_action = action_loaded.ActionModule(action) Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/home/pi/Mycodo/mycodo/actions/mqtt_publish.py", line 134, in init Jun 19 05:01:41 Mycodo-LIVE python[475]: super().init(action_dev, testing=testing, name=name) Jun 19 05:01:41 Mycodo-LIVE python[475]: File "/var/mycodo-root/mycodo/actions/base_action.py", line 42, in init Jun 19 05:01:41 Mycodo-LIVE python[475]: self.setup_logger(testing=testing, name=name, action=action_dev) Jun 19 05:01:41 Mycodo-LIVE python[475]: 2023-06-19 05:01:07,557 Error raised in session_scope. Session will be rolled back: db_uri='sqlite:////home/pi/Mycodo/databases/mycodo.db', error='(sqlite3.OperationalError) database is locked Jun 19 05:01:41 Mycodo-LIVE python[475]: [SQL: SELECT function_actions.id AS function_actions_id, function_actions.unique_id AS function_actions_unique_id, function_actions.function_id AS function_actions_function_id, function_actions.function_type AS function_actions_function_type, function_actions.action_type AS function_actions_action_type, function_actions.custom_options AS function_actions_custom_options, function_actions.pause_duration AS function_actions_pause_duration, function_actions.do_unique_id AS function_actions_do_unique_id, function_actions.do_action_string AS function_actions_do_action_string, function_actions.do_output_state AS function_actions_do_output_state, function_actions.do_output_amount AS function_actions_do_output_amount, function_actions.do_output_duration AS function_actions_do_output_duration, function_actions.do_output_pwm AS function_actions_do_output_pwm, function_actions.do_output_pwm2 AS function_actions_do_output_pwm2, function_actions.do_camera_duration AS function_actions_do_camera_duration, function_actions.remote AS function_actions_remote, function_actions.code AS function_actions_code, function_actions.send_times AS function_actions_send_times Jun 19 05:01:41 Mycodo-LIVE python[475]: FROM function_actions Jun 19 05:01:41 Mycodo-LIVE python[475]: WHERE (function_actions.unique_id LIKE ? || '%') Jun 19 05:01:41 Mycodo-LIVE python[475]: LIMIT ? OFFSET ?] Jun 19 05:01:41 Mycodo-LIVE python[475]: [parameters: ('9c798bf5', 1, 0)] Jun 19 05:01:41 Mycodo-LIVE python[475]: (Background on this error at: https://sqlalche.me/e/20/e3q8)' Jun 19 05:01:41 Mycodo-LIVE python[475]: Traceback (most recent call last):

LucidEye commented 1 year ago

It looks like the 2 processes that eventually use up all the CPU and RAM are:

PID-486 user-root - /var/mycodo-root/env/python /var/mycodo-root/mycodo/mycodo_daemon.py PID-402 user-influxdb - /usr/bin/influxd

So what is the next step to getting this fixed?

kizniche commented 1 year ago

Is any of this useful?

Nope, your load averages and RAM usage appear normal in the screenshot.

kizniche commented 1 year ago

Like I mentioned before, it's likely a filesystem issue. You need to use deduction to find the issue.

LucidEye commented 1 year ago

Like I mentioned before, it's likely a filesystem issue. You need to use deduction to find the issue.

Sorry, I don't see anywhere in your previous posts where you mentioned it possibly being a "filesystem error". Can you please elaborate on that a bit?

In the meantime I seem to maybe have made some progress... I turned off only the inputs I really don't need to keep the HVAC and hydroponics systems running... and interestingly enough, so far I haven't had a crash yet for the past 24 hours. I say interesting, because I only deactivated these 4 inputs, and they are all R-Pi self-monitoring Inputs. Screenshot at 2023-06-26 17-18-29 So one of these 4 Inputs (or a combination of them) are the most likely culprit causing all this mayhem I guess? I am going to wait for another 24 hours, and then start activating those inputs one by one, waiting at least 24 hours in between.... this is the glorious part of bug hunting, right? :-P I'll let you know what I find out.

kizniche commented 1 year ago

I don't see anywhere in your previous posts where you mentioned it possibly being a "filesystem error".

My mistake. I usually start with that as a possibility when I haven't seen a particular issue before and it's the easiest thing to rule out by moving to a new hard drive.

I haven't had a crash yet for the past 24 hours

Disabling all controllers (or some) and enabling until the issue presents itself is good. It could be a specific controller or just maybe the quantity of controllers that's the issue. Keep me posted.

LucidEye commented 1 year ago

Quantity of controllers? I mean I understand that any machine has it's limits depending on it's resources, but is there a theoretical limit for a Pi 4 2GB? I have noticed that after a reboot, the memory usage slowly creeps up over a 24 hour period from about 400MB to around 900MB before the system crashed. And when you say "controllers" are you referring to just Functions, or all modules... Inputs, Outputs, and Functions? I only have 3 physical sensors attached to this Pi on i2c, the other sensors are 2 mqtt remotes, and the OpenWeather API (which I will be getting rid of as soon as I get a weatherproof sensor setup outside). The only other inputs I had setup were all the built-in sensors for monitoring the Pi itself.... and the reason I disabled those is because the CPU temp and load were the inputs that I kept seeing the most popping up in the error logs saying they "could not acquire a measurement". As far as Functions go, I have about 60 total, but only about 20 of them are ever active at any given time.... and I'm very careful to make sure none of them conflict with each other.

One other question I did have is what is the recommended minimum Period time for an Input or a Function "cycle"... since my grow space is so small, I really need fast reaction times between Input reading and Output action to maintain a stable environment.... so a couple of my Inputs (humidity/vpd) and their associated Functions (humidistat bang bang) are set to 5 or 3 second Periods. Is this too fast for the Pi and Mycodo and Influxdb to keep up with? I mean right now everything still seems to be running smoothly, no log errors at all so far.... and still no crashes.

LucidEye commented 1 year ago

Ok, I caught it in the act this time. It seems this is what is causing the crash... this happened completely out of the blue and just keeps happening until the database eventually becomes locked and at that point everything is unresponsive. Prior to this error, there are no other errors in the log... this just suddenly happens and then it keeps repeating and causing other errors. Function 3397e924 is my humidistat bang-bang... same function worked just fine on the 32-bit system with influxdb v1. The Kasa HS300 output 4c46969e is my humidifier.

2023-06-27 22:40:28,392 - ERROR - mycodo.controllers.controller_function_3397e924 - Exception while running loop() Traceback (most recent call last): File "/var/mycodo-root/env/lib/python3.9/site-packages/Pyro5/socketutil.py", line 132, in receive_data chunk = sock.recv(size, socket.MSG_WAITALL) socket.timeout: timed out

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "/var/mycodo-root/mycodo/controllers/controller_function.py", line 79, in loop self.run_function.loop() File "/home/pi/Mycodo/mycodo/functions/bang_bang.py", line 206, in loop self.control.output_on( File "/var/mycodo-root/mycodo/mycodo_client.py", line 204, in output_on return self.proxy().output_on( File "/var/mycodo-root/env/lib/python3.9/site-packages/Pyro5/client.py", line 510, in call return self.send(self.name, args, kwargs) File "/var/mycodo-root/env/lib/python3.9/site-packages/Pyro5/client.py", line 256, in _pyroInvoke msg = protocol.recv_stub(self._pyroConnection, [protocol.MSG_RESULT]) File "/var/mycodo-root/env/lib/python3.9/site-packages/Pyro5/protocol.py", line 189, in recv_stub header = connection.recv(6) # 'PYRO' + 2 bytes protocol version File "/var/mycodo-root/env/lib/python3.9/site-packages/Pyro5/socketutil.py", line 435, in recv return receive_data(self.sock, size) File "/var/mycodo-root/env/lib/python3.9/site-packages/Pyro5/socketutil.py", line 140, in receive_data raise TimeoutError("receiving: timeout") Pyro5.errors.TimeoutError: receiving: timeout 2023-06-27 22:40:28,583 - ERROR - mycodo.outputs.on_off_kasa_hs300_0_4_2_4c46969e - Could not check Trigger for channel 3 of output 4c46969e-de6d-4747-a582-738cea12d651: receiving: timeout 2023-06-27 22:41:00,332 - ERROR - mycodo.controllers.controller_function_3397e924 - Exception while running loop() Traceback (most recent call last): File "/var/mycodo-root/env/lib/python3.9/site-packages/Pyro5/socketutil.py", line 132, in receive_data chunk = sock.recv(size, socket.MSG_WAITALL) socket.timeout: timed out

LucidEye commented 1 year ago

When booting up, does Mycodo start the inputs and functions in a specific order each time, or is it just random? From some of the log errors I'm seeing at boot up, it seems like there are functions being activated before the inputs they are tied to are activated or able to take a measurement, and this causes the same error that I am seeing right before these crashes I'm still experiencing. just had another crash while I was sitting in front of my computer and grabbed this error from the log. Prior to this error there were no other errors.

2023-07-04 10:30:40,872 - ERROR - mycodo.action.input_action_equation_4b6262f9 - Error parsing option: {'id': 'measurement', 'type': 'select_measurement_from_this_input', 'default_value': None, 'name': l'Measurement', 'phrase': 'Select the measurement to send as the payload'} Traceback (most recent call last): File "/var/mycodo-root/mycodo/abstract_base_controller.py", line 261, in setup_custom_options_json len(each_value.split(',')) > 1): AttributeError: 'NoneType' object has no attribute 'split' 2023-07-04 10:30:40,904 - ERROR - mycodo.action.input_action_equation_4b6262f9 - Error: A measurement needs to be selected as the payload.

Does this suggest to you where the problem might be?

LucidEye commented 1 year ago

Well, I've been running another SHTC3 for a while now, and it is still crashing, same problem. I get this error and then the Pi hangs, can't SSH in, can't access the web GUI, hard reboot is the only "fix".

After some more googling of that specific error, I found that it is a problem with circuit python.
So Mycodo either needs to use a different library for that sensor, or maybe take that sensor off the Mycodo compatibility list until the circuit python library gets fixed as this sensor is not reliable for automation as long as this bug in the library persists.

The problem has something to do with how the library sends a wake-up command to the sensor after it has gone into low-power mode between sampling intervals or something like that. What happens is the sensor works fine at first power up, then works for a while, but after some time the sensor will go into a sleep cycle and for some reason it does not wake up properly and the only way to reset the sensor is a hard power cycle, which means also hard cycling the Pi it's attached to. This problem is also showing up on other I2C devices that apparently do not use standard I2C communications protocols.

Incidentally, ever since I switched out the sensors several weeks ago, I've been running the "old" SHTC3 sensor that was in the hydroponics system on an ESP32, and it has had no issues, so that would seem to help corroborate that the problem may still be in the circuit python library that Mycodo is using.

kizniche commented 1 year ago

Have you verified the issue persists with the latest version?

https://github.com/kizniche/Mycodo/blob/25e09aa5afb4c5c8b61c50cdbb3878c519fffdb6/mycodo/inputs/shtc3_circuitpython.py#L49

kizniche commented 1 year ago

Looks like it's already been fixed:

https://github.com/adafruit/Adafruit_CircuitPython_SHTC3/pull/3 https://github.com/adafruit/circuitpython/issues/3821

LucidEye commented 1 year ago

Yeah, they claim it was fixed, but I am still seeing this same error, and I am seeing others posting that they are still seeing this same error. The error seems to be pretty random. From what I've read, it is these non-protocol-compliant I2C sensors that cause timing errors in the I2C bus. It sounds like they were able to fix the problem with some of these sensors in the library, but I have seen posts that say it is a hardware issue built into the sensor itself, and thus cannot be fixed?

LucidEye commented 1 year ago

Have you verified the issue persists with the latest version?

https://github.com/kizniche/Mycodo/blob/25e09aa5afb4c5c8b61c50cdbb3878c519fffdb6/mycodo/inputs/shtc3_circuitpython.py#L49

Is this package supposed to be installed in pip? Because when I do a "pip list" it does not show this package as being installed.

Mycodo-LIVE:~ $ pip list Package Version


certifi 2020.6.20 chardet 4.0.0 colorzero 1.1 distlib 0.3.6 distro 1.5.0 filelock 3.12.0 gpiozero 1.6.2 idna 2.10 numpy 1.19.5 picamera2 0.3.9 pidng 4.0.9 piexif 1.1.3 pigpio 1.78 Pillow 8.1.2 pip 23.2.1 platformdirs 2.6.2 python-apt 2.2.1 python-prctl 1.7 requests 2.25.1 RPi.GPIO 0.7.0 setuptools 52.0.0 simplejpeg 1.6.4 six 1.16.0 spidev 3.5 ssh-import-id 5.10 toml 0.10.1 urllib3 1.26.5 v4l2-python3 0.3.2 virtualenv 20.17.1 wheel 0.34.2

kizniche commented 1 year ago

Change the version number on that line, save, restart the frontend, go to Inputs page and add a new sensor, install the updated version from the popup, the daemon will automatically restart and start using the new version.

LucidEye commented 1 year ago

How do I check to see what version I already have installed?

I just recently upgraded Mycodo to 8.15.9... doesn't this install the latest version of that library?

LucidEye commented 1 year ago

Change the version number on that line, save, restart the frontend, go to Inputs page and add a new sensor, install the updated version from the popup, the daemon will automatically restart and start using the new version.

So I need to change the "adafruit_circuitpython_shtc3==1.1.2" to "adafruit_circuitpython_shtc3==1.1.12".... correct?

Do I need to delete the old Input for that sensor and use the new one I just added, or will the old Input for that sensor now use the new library?

LucidEye commented 1 year ago

So I made that edit, restarted the frontend, installed a new SHTC3 sensor, went through the dependency install, And I am continuing to use the old SHTC3 input I already had... assuming that it is now using the new adafruit_circuitpython_shtc3==1.1.12 library.

The sensor looks like it is working... I will have to wait and see if it still has this IO error 121. Could be at least a week or 2 before I know if the problem still persists... will update after observing for a while.

LucidEye commented 1 year ago

Ok, it looks like changing that library has actually made the problem worse.

I am now seeing that IO Error 121 pop up several times a day, it was not doing this before changing the library....

2023-09-21 13:43:19,184 - INFO - mycodo.function.bang_bang_947d8cb5 - Bang-Bang controller started with options: Measurement Device: d481115f-863c-4aa7-89b4-922e613d8b2a, Measurement: fa2a915c-9c3d-4b1a-8aaf-61de48c40cc6, Output: cfaaccb0-2860-4eac-ae1d-aa77b9f6eb04, Output_Channel: 0, Setpoint: 78.3, Hysteresis: 0.3, Direction: lower, Period: 15.0 2023-09-21 13:43:19,185 - INFO - mycodo.controllers.controller_function_947d8cb5 - Activated in 585.7 ms 2023-09-21 13:43:30,388 - INFO - mycodo.function.bang_bang_4264d6bd - Bang-Bang controller started with options: Measurement Device: d481115f-863c-4aa7-89b4-922e613d8b2a, Measurement: fa2a915c-9c3d-4b1a-8aaf-61de48c40cc6, Output: ceb7418b-d5da-4c23-b017-d651655d7ac7, Output_Channel: 0, Setpoint: 76.5, Hysteresis: 0.4, Direction: lower, Period: 15.0 2023-09-21 13:43:30,389 - INFO - mycodo.controllers.controller_function_4264d6bd - Activated in 139.5 ms 2023-09-21 13:44:35,226 - INFO - mycodo.controllers.controller_function_947d8cb5 - Deactivated in 312.0 ms 2023-09-21 15:10:34,793 - ERROR - mycodo.inputs.shtc3_circuitpython_fc05a536 - InputModule.get_measurement() method raised IOError: [Errno 121] Remote I/O error 2023-09-21 15:56:24,754 - ERROR - mycodo.inputs.shtc3_circuitpython_fc05a536 - InputModule.get_measurement() method raised IOError: [Errno 121] Remote I/O error 2023-09-21 17:03:14,727 - ERROR - mycodo.inputs.shtc3_circuitpython_fc05a536 - InputModule.get_measurement() method raised IOError: [Errno 121] Remote I/O error 2023-09-21 18:56:14,743 - ERROR - mycodo.inputs.shtc3_circuitpython_fc05a536 - InputModule.get_measurement() method raised IOError: [Errno 121] Remote I/O error 2023-09-21 19:08:09,768 - ERROR - mycodo.inputs.shtc3_circuitpython_fc05a536 - InputModule.get_measurement() method raised IOError: [Errno 121] Remote I/O error 2023-09-21 19:31:54,143 - INFO - mycodo.controllers.controller_function_4264d6bd - Deactivated in 461.0 ms 2023-09-21 19:31:57,817 - INFO - mycodo.controllers.controller_trigger_969cf0cf - Deactivated in 55.4 ms 2023-09-21 19:31:58,827 - INFO - mycodo.controllers.controller_trigger_95f1f490 - Deactivated in 152.6 ms 2023-09-21 22:00:49,748 - ERROR - mycodo.inputs.shtc3_circuitpython_fc05a536 - InputModule.get_measurement() method raised IOError: [Errno 121] Remote I/O error 2023-09-21 22:19:39,773 - ERROR - mycodo.inputs.shtc3_circuitpython_fc05a536 - InputModule.get_measurement() method raised IOError: [Errno 121] Remote I/O error 2023-09-21 22:44:09,761 - ERROR - mycodo.inputs.shtc3_circuitpython_fc05a536 - InputModule.get_measurement() method raised IOError: [Errno 121] Remote I/O error 2023-09-21 23:01:01,356 - INFO - mycodo.controllers.controller_trigger_49d6c108 - Deactivated in 201.7 ms 2023-09-21 23:01:01,613 - INFO - mycodo.controllers.controller_function_3397e924 - Deactivated in 768.7 ms 2023-09-21 23:01:02,112 - INFO - mycodo.controllers.controller_trigger_6fdac2b6 - Deactivated in 348.6 ms 2023-09-21 23:15:34,725 - ERROR - mycodo.inputs.shtc3_circuitpython_fc05a536 - InputModule.get_measurement() method raised IOError: [Errno 121] Remote I/O error 2023-09-21 23:45:59,772 - ERROR - mycodo.inputs.shtc3_circuitpython_fc05a536 - InputModule.get_measurement() method raised IOError: [Errno 121] Remote I/O error 2023-09-21 23:58:24,729 - ERROR - mycodo.inputs.shtc3_circuitpython_fc05a536 - InputModule.get_measurement() method raised IOError: [Errno 121] Remote I/O error 2023-09-22 00:01:09,750 - ERROR - mycodo.inputs.shtc3_circuitpython_fc05a536 - InputModule.get_measurement() method raised IOError: [Errno 121] Remote I/O error 2023-09-22 01:40:29,823 - ERROR - mycodo.inputs.shtc3_circuitpython_fc05a536 - InputModule.get_measurement() method raised IOError: [Errno 121] Remote I/O error 2023-09-22 02:56:09,786 - ERROR - mycodo.inputs.shtc3_circuitpython_fc05a536 - InputModule.get_measurement() method raised IOError: [Errno 121] Remote I/O error 2023-09-22 03:09:54,860 - ERROR - mycodo.inputs.shtc3_circuitpython_fc05a536 - InputModule.get_measurement() method raised IOError: [Errno 121] Remote I/O error 2023-09-22 04:00:34,723 - ERROR - mycodo.inputs.shtc3_circuitpython_fc05a536 - InputModule.get_measurement() method raised IOError: [Errno 121] Remote I/O error 2023-09-22 04:05:54,727 - ERROR - mycodo.inputs.shtc3_circuitpython_fc05a536 - InputModule.get_measurement() method raised IOError: [Errno 121] Remote I/O error 2023-09-22 05:01:00,760 - INFO - mycodo.controllers.controller_trigger_49d6c108 - Activated in 132.1 ms 2023-09-22 05:01:01,166 - INFO - mycodo.controllers.controller_trigger_6fdac2b6 - Activated in 159.8 ms 2023-09-22 05:01:01,527 - INFO - mycodo.function.bang_bang_3397e924 - Bang-Bang controller started with options: Measurement Device: 6c261530-3ac8-4482-8800-8035cecf95cb, Measurement: d3460c2b-df14-4c72-b854-e4944ca156d9, Output: 4c46969e-de6d-4747-a582-738cea12d651, Output_Channel: 3, Setpoint: 1.0, Hysteresis: 0.03, Direction: lower, Period: 3.0 2023-09-22 05:01:01,528 - INFO - mycodo.controllers.controller_function_3397e924 - Activated in 168.2 ms 2023-09-22 05:10:29,902 - ERROR - mycodo.inputs.shtc3_circuitpython_fc05a536 - InputModule.get_measurement() method raised IOError: [Errno 121] Remote I/O error 2023-09-22 06:58:04,764 - ERROR - mycodo.inputs.shtc3_circuitpython_fc05a536 - InputModule.get_measurement() method raised IOError: [Errno 121] Remote I/O error 2023-09-22 07:10:39,790 - ERROR - mycodo.inputs.shtc3_circuitpython_fc05a536 - InputModule.get_measurement() method raised IOError: [Errno 121] Remote I/O error 2023-09-22 07:33:14,722 - ERROR - mycodo.inputs.shtc3_circuitpython_fc05a536 - InputModule.get_measurement() method raised IOError: [Errno 121] Remote I/O error 2023-09-22 08:47:34,776 - ERROR - mycodo.inputs.shtc3_circuitpython_fc05a536 - InputModule.get_measurement() method raised IOError: [Errno 121] Remote I/O error 2023-09-22 09:38:49,793 - ERROR - mycodo.inputs.shtc3_circuitpython_fc05a536 - InputModule.get_measurement() method raised IOError: [Errno 121] Remote I/O error 2023-09-22 09:47:34,762 - ERROR - mycodo.inputs.shtc3_circuitpython_fc05a536 - InputModule.get_measurement() method raised IOError: [Errno 121] Remote I/O error 2023-09-22 10:17:39,761 - ERROR - mycodo.inputs.shtc3_circuitpython_fc05a536 - InputModule.get_measurement() method raised IOError: [Errno 121] Remote I/O error 2023-09-22 13:23:29,836 - ERROR - mycodo.inputs.shtc3_circuitpython_fc05a536 - InputModule.get_measurement() method raised IOError: [Errno 121] Remote I/O error 2023-09-22 13:37:49,842 - ERROR - mycodo.inputs.shtc3_circuitpython_fc05a536 - InputModule.get_measurement() method raised IOError: [Errno 121] Remote I/O error 2023-09-22 15:12:34,830 - ERROR - mycodo.inputs.shtc3_circuitpython_fc05a536 - InputModule.get_measurement() method raised IOError: [Errno 121] Remote I/O error 2023-09-22 15:29:19,829 - ERROR - mycodo.inputs.shtc3_circuitpython_fc05a536 - InputModule.get_measurement() method raised IOError: [Errno 121] Remote I/O error 2023-09-22 15:49:19,836 - ERROR - mycodo.inputs.shtc3_circuitpython_fc05a536 - InputModule.get_measurement() method raised IOError: [Errno 121] Remote I/O error 2023-09-22 15:58:29,751 - ERROR - mycodo.inputs.shtc3_circuitpython_fc05a536 - InputModule.get_measurement() method raised IOError: [Errno 121] Remote I/O error 2023-09-22 19:10:34,793 - ERROR - mycodo.inputs.shtc3_circuitpython_fc05a536 - InputModule.get_measurement() method raised IOError: [Errno 121] Remote I/O error 2023-09-22 19:15:29,844 - ERROR - mycodo.inputs.shtc3_circuitpython_fc05a536 - InputModule.get_measurement() method raised IOError: [Errno 121] Remote I/O error 2023-09-22 20:14:54,729 - ERROR - mycodo.inputs.shtc3_circuitpython_fc05a536 - InputModule.get_measurement() method raised IOError: [Errno 121] Remote I/O error 2023-09-22 22:13:55,137 - INFO - mycodo.controllers.controller_trigger_1d11f1a1 - Deactivated in 112.3 ms 2023-09-22 22:14:01,450 - INFO - mycodo.controllers.controller_function_3397e924 - Deactivated in 371.5 ms 2023-09-22 22:50:24,791 - ERROR - mycodo.inputs.shtc3_circuitpython_fc05a536 - InputModule.get_measurement() method raised IOError: [Errno 121] Remote I/O error 2023-09-22 22:54:40,585 - INFO - mycodo.function.bang_bang_3397e924 - Bang-Bang controller started with options: Measurement Device: 6c261530-3ac8-4482-8800-8035cecf95cb, Measurement: d3460c2b-df14-4c72-b854-e4944ca156d9, Output: 4c46969e-de6d-4747-a582-738cea12d651, Output_Channel: 3, Setpoint: 1.0, Hysteresis: 0.03, Direction: lower, Period: 3.0 2023-09-22 22:54:40,587 - INFO - mycodo.controllers.controller_function_3397e924 - Activated in 164.9 ms 2023-09-22 22:54:42,768 - INFO - mycodo.controllers.controller_trigger_1d11f1a1 - Activated in 140.3 ms 2023-09-22 23:01:01,811 - INFO - mycodo.controllers.controller_trigger_49d6c108 - Deactivated in 241.0 ms 2023-09-22 23:01:01,890 - INFO - mycodo.controllers.controller_function_3397e924 - Deactivated in 801.9 ms 2023-09-22 23:01:02,593 - INFO - mycodo.controllers.controller_trigger_6fdac2b6 - Deactivated in 210.2 ms 2023-09-22 23:25:09,727 - ERROR - mycodo.inputs.shtc3_circuitpython_fc05a536 - InputModule.get_measurement() method raised IOError: [Errno 121] Remote I/O error 2023-09-23 00:24:28,584 - INFO - mycodo.controllers.controller_input_ef2eb196 - Deactivated in 1012.8 ms 2023-09-23 00:24:40,015 - INFO - mycodo.controllers.controller_input_ef2eb196 - Activated in 392.2 ms 2023-09-23 00:24:40,017 - INFO - mycodo.inputs.mqtt_paho_ef2eb196 - Connected to 192.168.3.39 as client_mHgn0zgD 2023-09-23 00:49:39,733 - ERROR - mycodo.inputs.shtc3_circuitpython_fc05a536 - InputModule.get_measurement() method raised IOError: [Errno 121] Remote I/O error 2023-09-23 01:26:59,796 - ERROR - mycodo.inputs.shtc3_circuitpython_fc05a536 - InputModule.get_measurement() method raised IOError: [Errno 121] Remote I/O error 2023-09-23 01:37:54,864 - ERROR - mycodo.inputs.shtc3_circuitpython_fc05a536 - InputModule.get_measurement() method raised IOError: [Errno 121] Remote I/O error 2023-09-23 02:16:44,768 - ERROR - mycodo.inputs.shtc3_circuitpython_fc05a536 - InputModule.get_measurement() method raised IOError: [Errno 121] Remote I/O error

Error times seem to be completely random.

The system has crashed once this week and still needed a hard reboot to regain control.

I am also seeing 4 different I2C busses? Is this because it's a Pi 4? I don't remember ever seeing 4 I2C busses before. Screenshot at 2023-09-23 02-56-24

The only one of these I2C busses that have any sensors attached is Bus 1, and these device addresses are correct... Screenshot at 2023-09-23 03-07-46

What would cause the "phantom" devices that appear on "Bus 10" and "Bus 22"?

I am still not having any errors or data dropouts with this exact same sensor attached to an ESP32.

I am going to try adjusting the I2C baud rate again to see if that might help... unless you have any ideas?

LucidEye commented 1 year ago

System is still crashing!!! 2023-09-29 00:12:35,860 - INFO - mycodo.controllers.controller_trigger_6f035328 - Activated in 491.8 ms 2023-09-29 01:18:49,762 - ERROR - mycodo.controllers.controller_conditional_8cb60bed - Exception executing Run Python Code Traceback (most recent call last): File "/var/mycodo-root/env/lib/python3.9/site-packages/Pyro5/socketutil.py", line 132, in receive_data chunk = sock.recv(size, socket.MSG_WAITALL) socket.timeout: timed out

During handling of the above exception, another exception occurred:

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/pi/Mycodo/mycodo/user_python_code/conditional_8cb60bed-af46-471f-a1d5-faca410bee6f.py", line 25, in conditional_code_run self.run_action("f5afde97", value={"payload": "0,0,0"}) File "/var/mycodo-root/mycodo/controllers/base_conditional.py", line 60, in run_action return_dict = self.control.trigger_action( File "/var/mycodo-root/mycodo/mycodo_client.py", line 146, in trigger_action return self.proxy().trigger_action( File "/var/mycodo-root/env/lib/python3.9/site-packages/Pyro5/client.py", line 510, in call return self.send(self.name, args, kwargs) File "/var/mycodo-root/env/lib/python3.9/site-packages/Pyro5/client.py", line 256, in _pyroInvoke msg = protocol.recv_stub(self._pyroConnection, [protocol.MSG_RESULT]) File "/var/mycodo-root/env/lib/python3.9/site-packages/Pyro5/protocol.py", line 189, in recv_stub header = connection.recv(6) # 'PYRO' + 2 bytes protocol version File "/var/mycodo-root/env/lib/python3.9/site-packages/Pyro5/socketutil.py", line 435, in recv return receive_data(self.sock, size) File "/var/mycodo-root/env/lib/python3.9/site-packages/Pyro5/socketutil.py", line 140, in receive_data raise TimeoutError("receiving: timeout") Pyro5.errors.TimeoutError: receiving: timeout 2023-09-29 01:18:52,527 - ERROR - mycodo.controllers.controller_conditional_c180b54a - Exception executing Run Python Code Traceback (most recent call last): File "/var/mycodo-root/env/lib/python3.9/site-packages/Pyro5/socketutil.py", line 132, in receive_data chunk = sock.recv(size, socket.MSG_WAITALL) socket.timeout: timed out

During handling of the above exception, another exception occurred:

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/pi/Mycodo/mycodo/user_python_code/conditional_c180b54a-a92c-452f-bb20-fbf7067c7825.py", line 22, in conditional_code_run measurement = self.condition("1deef501") # Replace ID with correct Conditional ID File "/var/mycodo-root/mycodo/controllers/base_conditional.py", line 78, in condition return self.control.get_condition_measurement(full_cond_id) File "/var/mycodo-root/mycodo/mycodo_client.py", line 184, in get_condition_measurement return self.proxy().get_condition_measurement(condition_id) File "/var/mycodo-root/env/lib/python3.9/site-packages/Pyro5/client.py", line 510, in call return self.send(self.name, args, kwargs) File "/var/mycodo-root/env/lib/python3.9/site-packages/Pyro5/client.py", line 256, in _pyroInvoke msg = protocol.recv_stub(self._pyroConnection, [protocol.MSG_RESULT]) File "/var/mycodo-root/env/lib/python3.9/site-packages/Pyro5/protocol.py", line 189, in recv_stub header = connection.recv(6) # 'PYRO' + 2 bytes protocol version File "/var/mycodo-root/env/lib/python3.9/site-packages/Pyro5/socketutil.py", line 435, in recv return receive_data(self.sock, size) File "/var/mycodo-root/env/lib/python3.9/site-packages/Pyro5/socketutil.py", line 140, in receive_data raise TimeoutError("receiving: timeout") Pyro5.errors.TimeoutError: receiving: timeout 2023-09-29 01:18:52,544 - ERROR - mycodo.controllers.controller_conditional_45c4d3c5 - Exception executing Run Python Code Traceback (most recent call last): File "/var/mycodo-root/env/lib/python3.9/site-packages/Pyro5/socketutil.py", line 132, in receive_data chunk = sock.recv(size, socket.MSG_WAITALL) socket.timeout: timed out

Why is it giving me these errors that say "# Replace ID with correct Conditional ID" ??? I haven't changed anyof the conditional ID's, they are all correct!!!! WHAT IS GOING ON WITH YOUR SOFTWARE?????

kizniche commented 1 year ago

Why is it giving me these errors that say "# Replace ID with correct Conditional ID" ???

That's not an error. It is literally your line of code it is referencing.

LucidEye commented 1 year ago

The code checked out with pylint and has been running just fine for months, so why is it now suddenly throwing this error? It only does this after a crash. Something causes a crash and then the log starts filling up with all of these cascade errors. I doesn't make any sense.

kizniche commented 1 year ago

Pylint simply checks for syntax and convention errors, it can not possibly test all possible environments it runs in for errors, as it is not designed to do that.

LucidEye commented 1 year ago

Here is one of my conditionals. I have 8 of these, they are all pretty much the same, all they do is read a condition from a sensor and then turn on LEDs on a remote ESP32. I ran this code by you months ago and you said it looked ok. It doesn't make sense to me why they would run fine for days and then suddenly start throwing errors for no apparent reason. Screenshot at 2023-09-29 21-53-58 Is it possible that python itself is the issue here... maybe because it is slower executing than other languages? Maybe that is why I keep getting these timeout errors? I mean it really shouldn't take more than a few milliseconds to run this small bit of code, right?

LucidEye commented 1 year ago

Why is it giving me these errors that say "# Replace ID with correct Conditional ID" ???

That's not an error. It is literally your line of code it is referencing.

Thank you for pointing that out. What I have done is replace that comment line so that it now shows the name of each of my Conditional Functions. This should now hopefully make things a bit more clear when trying to figure out the logs. I've also created text files of the full conditional code as copied from Mycodo after doing a save in the conditional setup. This should hopefully make it easier to understand the traceback errors in the log when they reference the conditional code.

It still seems like the root of the problem is that Mycodo randomly can't acquire the humidity reading from the SHTC3 for some reason, and then because of that the VPD calculation Function also no longer can provide a measurement to Mycodo and then the VPD bang-bang function starts throwing errors, and then everything starts to unravel from there. I tried reducing the period on the SHTC3 Input a couple of seconds to see if that might help.

LucidEye commented 1 year ago

What would cause this? image

I just did a reboot from another crash and now this is happening... I can't force any measurements, and no measurements seem to be happening now.

I had to manually deactivate all my sensor inputs and reactivate them after the reboot to start getting measurements again, had to do the same thing with the VDP Function to get that to start getting measurements again. Why would that happen? shouldn't those have been reset on the reboot???

LucidEye commented 11 months ago

UPDATE:

I had been running all of this on a Pi 4B, but I needed that Pi4 for something else... so I switched Mycodo back to a Pi 3B+. I still had the crashing issues... and I noticed that the Pi 3B+ was running MUCH slower than it was previously before I switched Mycodo over to the Pi4B.

The errors I keep seeing the most in the log seem to point to I/O problems of one kind or another. Since I've gone over all the hardware and wiring, and replaced the Pi and all of the sensors with spares, and I am still getting the same crashes and I/O errors... maybe the issue is with the OS itself? This was installed on the newest version of Bullseye (at the time 7 months ago). I can only assume that the OS received some upgrades that made it run better on the newer Pi4 (and soon to be released Pi 5) and made it run slower on the older models.

I decided to try increasing all of the Timeout periods on all of my Conditionals to about 60 seconds. This reduced the frequency of crashes a bit, but it was still happening about once a week.

Next I decided to try increasing I/O speeds a bit by overclocking the SD card reader on the Pi 3B+. By default, the Pi 2 and 3 models have their SD card reader clocked at 50MHz. Newer High-Speed SD cards are capable of being clocked at 100MHZ I have used this "hack" many times in the past and it is completely safe as long as you are using a good quality SD card that is rated for high-speed data transfer. This is irrelevant on a Pi4 since it has completely different hardware.

On a Pi 2 or 3 you can check the speed of the SD card reader as well as the type of SD card in the slot by typing this in the console:

sudo cat /sys/kernel/debug/mmc0/ios

The output will look something like this:

clock: 50000000 Hz actual clock: 50000000 Hz vdd: 21 (3.3 ~ 3.4 V) bus mode: 2 (push-pull) chip select: 0 (don't care) power mode: 2 (on) bus width: 2 (4 bits) timing spec: 2 (sd default-speed) signal voltage: 0 (3.30 V) driver type: 0 (driver type B)

Note the bold-type lines above... this is what you will see if you are using the default clock timing and an older standard speed SD card.

Now use a high-speed SD card, and enter the following line in /boot/config.txt under the [all] section at the end of the file...

dtparam=sd_overclock=100

Reboot the Pi and enter this again...

sudo cat /sys/kernel/debug/mmc0/ios

Now the output should look like this...

clock: 50000000 Hz actual clock: 100000000 Hz vdd: 21 (3.3 ~ 3.4 V) bus mode: 2 (push-pull) chip select: 0 (don't care) power mode: 2 (on) bus width: 2 (4 bits) timing spec: 2 (sd high-speed) signal voltage: 0 (3.30 V) driver type: 0 (driver type B)

This increase in I/O speed for SD card read/writes has so far seemed to reduce the frequency of crashes due to I/O errors. I have still had a few times where the system was reporting a missing measurement, but instead of crashing, the system seemed to recover after finally getting a measurement instead of locking the database. I can only assume this is due to the improved I/O speed.

This still doesn't explain why I was having these problems on the Pi 4 since it's SD card reader is by default faster than the Pi 3.

Either way, it would seem that possibly the newer 64-bit OS releases for the Pi are not capable of running quite as fast on older Pi hardware like the Pi 3 or 3B+... or the newer OS is capable of higher I/O throughput but the Pi's SD hardware is the speed limitation? Increasing I/O throughput seems to help. This can be done with the SD card overclock hack as mentioned above, or it can also be done by running the OS from a USB drive since the USB ports on the Pi 3 (and Pi 4) are faster than the SD card slot. I did not test this using a USB root drive, but judging by the improvement from the SD card reader hack, it would seem to hold true? Would be nice if someone could actually test this since I don't have any extra Pis at the moment.

LucidEye commented 11 months ago

Well, I spoke too soon, because it just crashed again....

2023-10-27 19:42:50,489 - ERROR - mycodo.controllers.controller_function_3397e924 - Exception while running loop() Traceback (most recent call last): File "/var/mycodo-root/env/lib/python3.9/site-packages/Pyro5/socketutil.py", line 132, in receive_data chunk = sock.recv(size, socket.MSG_WAITALL) socket.timeout: timed out

During handling of the above exception, another exception occurred:

Traceback (most recent call last): File "/var/mycodo-root/mycodo/controllers/controller_function.py", line 79, in loop self.run_function.loop() File "/home/pi/Mycodo/mycodo/functions/bang_bang.py", line 206, in loop self.control.output_on( File "/var/mycodo-root/mycodo/mycodo_client.py", line 207, in output_on return self.proxy().output_on( File "/var/mycodo-root/env/lib/python3.9/site-packages/Pyro5/client.py", line 510, in call return self.send(self.name, args, kwargs) File "/var/mycodo-root/env/lib/python3.9/site-packages/Pyro5/client.py", line 256, in _pyroInvoke msg = protocol.recv_stub(self._pyroConnection, [protocol.MSG_RESULT]) File "/var/mycodo-root/env/lib/python3.9/site-packages/Pyro5/protocol.py", line 189, in recv_stub header = connection.recv(6) # 'PYRO' + 2 bytes protocol version File "/var/mycodo-root/env/lib/python3.9/site-packages/Pyro5/socketutil.py", line 435, in recv return receive_data(self.sock, size) File "/var/mycodo-root/env/lib/python3.9/site-packages/Pyro5/socketutil.py", line 140, in receive_data raise TimeoutError("receiving: timeout") Pyro5.errors.TimeoutError: receiving: timeout 2023-10-27 19:42:56,263 - ERROR - mycodo.outputs.on_off_kasa_hs300_0_4_2_4c46969e - Could not check Trigger for channel 3 of output 4c46969e-de6d-4747-a582-738cea12d651: receiving: timeout 2023-10-27 19:42:56,270 - ERROR - mycodo.controllers.controller_input_d481115f - Pyro5 TimeoutError Traceback (most recent call last): File "/var/mycodo-root/env/lib/python3.9/site-packages/Pyro5/socketutil.py", line 132, in receive_data chunk = sock.recv(size, socket.MSG_WAITALL) socket.timeout: timed out

function_3397e924 is my humidistat bang-bang, the period is set to 7 seconds. I used to be able to run that period down to 3 seconds, in fact that is how I had been running it for the past 2 years I've been using Mycodo, but now for some reason even 7 seconds seems to be causing timeout errors???? Really wish I could get to the bottom of all these problems that I never used to have and suddenly started having for no apparent reason.