NSPManager / NSPanelManager

Sonoff NSPanel custom firmware for responsive and intuitive use
https://nspanelmanager.com/
128 stars 10 forks source link

Database is locked #51

Closed velijv closed 2 months ago

velijv commented 11 months ago

Using HomeAssistant Addon. Whille managing rooms and lights, when TFT was uploading:

OperationalError at /add_light/2
database is locked
Request Method: POST
Request URL:    http://homeassistant.local:8000/add_light/2
Django Version: 4.1.7
Exception Type: OperationalError
Exception Value:    
database is locked
Exception Location: /usr/local/lib/python3.11/site-packages/django/db/backends/sqlite3/base.py, line 357, in execute
Raised during:  web.views.add_light_to_room
Python Executable:  /usr/local/bin/python
Python Version: 3.11.4
Python Path:    
['/usr/src/app/nspanelmanager',
 '/usr/local/lib/python311.zip',
 '/usr/local/lib/python3.11',
 '/usr/local/lib/python3.11/lib-dynload',
 '/usr/local/lib/python3.11/site-packages']
Server time:    Mon, 17 Jul 2023 03:17:26 +0000

Environment:

Request Method: POST
Request URL: http://homeassistant.local:8000/add_light/2

Django Version: 4.1.7
Python Version: 3.11.4
Installed Applications:
['web',
 'mathfilters',
 'django.contrib.admin',
 'django.contrib.auth',
 'django.contrib.contenttypes',
 'django.contrib.sessions',
 'django.contrib.messages',
 'django.contrib.staticfiles']
Installed Middleware:
['django.middleware.security.SecurityMiddleware',
 'django.contrib.sessions.middleware.SessionMiddleware',
 'django.middleware.common.CommonMiddleware',
 'django.middleware.csrf.CsrfViewMiddleware',
 'django.contrib.auth.middleware.AuthenticationMiddleware',
 'django.contrib.messages.middleware.MessageMiddleware',
 'django.middleware.clickjacking.XFrameOptionsMiddleware']

Traceback (most recent call last):
  File "/usr/local/lib/python3.11/site-packages/django/db/backends/utils.py", line 89, in _execute
    return self.cursor.execute(sql, params)
  File "/usr/local/lib/python3.11/site-packages/django/db/backends/sqlite3/base.py", line 357, in execute
    return Database.Cursor.execute(self, query, params)

The above exception (database is locked) was the direct cause of the following exception:
  File "/usr/local/lib/python3.11/site-packages/django/core/handlers/exception.py", line 56, in inner
    response = get_response(request)
  File "/usr/local/lib/python3.11/site-packages/django/core/handlers/base.py", line 197, in _get_response
    response = wrapped_callback(request, *callback_args, **callback_kwargs)
  File "/usr/src/app/nspanelmanager/web/views.py", line 265, in add_light_to_room
    if not Light.objects.filter(room=room, room_view_position=i).exists():
  File "/usr/local/lib/python3.11/site-packages/django/db/models/query.py", line 1226, in exists
    return self.query.has_results(using=self.db)
  File "/usr/local/lib/python3.11/site-packages/django/db/models/sql/query.py", line 592, in has_results
    return compiler.has_results()
  File "/usr/local/lib/python3.11/site-packages/django/db/models/sql/compiler.py", line 1366, in has_results
    return bool(self.execute_sql(SINGLE))
  File "/usr/local/lib/python3.11/site-packages/django/db/models/sql/compiler.py", line 1398, in execute_sql
    cursor.execute(sql, params)
  File "/usr/local/lib/python3.11/site-packages/django/db/backends/utils.py", line 102, in execute
    return super().execute(sql, params)
  File "/usr/local/lib/python3.11/site-packages/django/db/backends/utils.py", line 67, in execute
    return self._execute_with_wrappers(
  File "/usr/local/lib/python3.11/site-packages/django/db/backends/utils.py", line 80, in _execute_with_wrappers
    return executor(sql, params, many, context)
  File "/usr/local/lib/python3.11/site-packages/django/db/backends/utils.py", line 84, in _execute
    with self.db.wrap_database_errors:
  File "/usr/local/lib/python3.11/site-packages/django/db/utils.py", line 91, in __exit__
    raise dj_exc_value.with_traceback(traceback) from exc_value
  File "/usr/local/lib/python3.11/site-packages/django/db/backends/utils.py", line 89, in _execute
    return self.cursor.execute(sql, params)
  File "/usr/local/lib/python3.11/site-packages/django/db/backends/sqlite3/base.py", line 357, in execute
    return Database.Cursor.execute(self, query, params)

Exception Type: OperationalError at /add_light/2
Exception Value: database is locked
tpanajott commented 11 months ago

Hm, never seen that before. Will have to take a look later. When you say "uploading TFT", do you mean uploading it to the panel or uploading it to the web interface?

velijv commented 11 months ago

At step

2.4 NSPanel configuration

Flash the new GUI file to the panel by pressing the "Actions"-button on the right and select "Update screen". Note: The flashing of the GUI file may be finicky and might require multiple tries before it succeeds. If it fails and reboots or you see a "System data error", just try again. • Continue on to create new rooms and add entities to your configuration. Continue with the section on the web interface and how it work here.

Screen was updating, meanwile i was exploring the web interface, and hitting save on a light got me this.

tpanajott commented 11 months ago

Okay. Thanks for the report. Will have to look into it.

tpanajott commented 11 months ago

It seems like this is an issue with the SQLite database as i though. Per Django documentation (https://docs.djangoproject.com/en/dev/ref/databases/#database-is-locked-errors) the problem is multiple concurrent access attempts to the database which SQLite isn't really built to handle.

tpanajott commented 11 months ago

There is room for optimization of database calls, in the "add_light_to_room" function in views.py when adding a light to the room view position, it should be possible to only make 1 database call instead of 12. There is also room for optimization when downloading the TFT. This can be optimized by Downloading multiple chunks at the time instead of just the 1 currently. (this is more information for me, you can ignore it @velijv)

velijv commented 11 months ago

Got similar logs from the Addon (not doing anything else but managing rooms):

   raise dj_exc_value.with_traceback(traceback) from exc_value
  File "/usr/local/lib/python3.11/site-packages/django/db/backends/utils.py", line 89, in _execute
    return self.cursor.execute(sql, params)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/django/db/backends/sqlite3/base.py", line 357, in execute
    return Database.Cursor.execute(self, query, params)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
django.db.utils.OperationalError: database is locked
ERROR:django.request:Internal Server Error: /api/set_panel_online_status/C0:49:EF:F8:CD:48/
Traceback (most recent call last):
  File "/usr/local/lib/python3.11/site-packages/django/db/backends/utils.py", line 89, in _execute
    return self.cursor.execute(sql, params)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/django/db/backends/sqlite3/base.py", line 357, in execute
    return Database.Cursor.execute(self, query, params)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
sqlite3.OperationalError: database is locked
The above exception was the direct cause of the following exception:
Traceback (most recent call last):
  File "/usr/local/lib/python3.11/site-packages/django/core/handlers/exception.py", line 56, in inner
    response = get_response(request)
               ^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/django/core/handlers/base.py", line 197, in _get_response
    response = wrapped_callback(request, *callback_args, **callback_kwargs)
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/django/views/decorators/csrf.py", line 55, in wrapped_view
    return view_func(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/app/nspanelmanager/web/api.py", line 379, in set_panel_online_status
    if nspanels.exists():
       ^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/django/db/models/query.py", line 1226, in exists
    return self.query.has_results(using=self.db)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/django/db/models/sql/query.py", line 592, in has_results
    return compiler.has_results()
           ^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/django/db/models/sql/compiler.py", line 1366, in has_results
    return bool(self.execute_sql(SINGLE))
                ^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/django/db/models/sql/compiler.py", line 1398, in execute_sql
    cursor.execute(sql, params)
  File "/usr/local/lib/python3.11/site-packages/django/db/backends/utils.py", line 102, in execute
    return super().execute(sql, params)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/django/db/backends/utils.py", line 67, in execute
    return self._execute_with_wrappers(
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/django/db/backends/utils.py", line 80, in _execute_with_wrappers
    return executor(sql, params, many, context)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/django/db/backends/utils.py", line 84, in _execute
    with self.db.wrap_database_errors:
  File "/usr/local/lib/python3.11/site-packages/django/db/utils.py", line 91, in __exit__
    raise dj_exc_value.with_traceback(traceback) from exc_value
  File "/usr/local/lib/python3.11/site-packages/django/db/backends/utils.py", line 89, in _execute
    return self.cursor.execute(sql, params)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/django/db/backends/sqlite3/base.py", line 357, in execute
    return Database.Cursor.execute(self, query, params)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
django.db.utils.OperationalError: database is locked
[17/Jul/2023 10:12:56] code 400, message Bad request version ('"192.168.1.135"}')
[17/Jul/2023 10:12:56] "{"state": "online", "rssi": -61, "heap_used_pct": 34, "mac": "C0:49:EF:F8:CD:48", "temperature": 34.61293793, "ip": "192.168.1.135"}" 400 -
[17/Jul/2023 10:12:56,117] - Broken pipe from ('127.0.0.1', 37354)
[17/Jul/2023 10:12:56] "GET /rooms/3/ HTTP/1.1" 200 23379
[17/Jul/2023 10:12:56] "GET /static/base.js?refresh=1689588776 HTTP/1.1" 200 517
[17/Jul/2023 10:12:56] "GET /static/edit_room.js?refresh=1689588776 HTTP/1.1" 200 10664
[17/Jul/2023 10:12:57] "GET /api/get_mqtt_manager_config HTTP/1.1" 200 2667
tpanajott commented 11 months ago

What hardware are you running the manager on?

tpanajott commented 2 months ago

Haven't heard back on this in a good while and haven't heard anyone else have this problem. Have also had this in the back of my mind when rewriting part of the code so this shouldn't happen any more. Will close.