Telemetry SQL error

[faragher]

Describe the Bug Telemetry eventually causes SQL failures.

To Reproduce Have not tried a fresh start, but this was a repeating issue.

Expected Behavior No SQL errors

Logs & Screenshots

Final log:

[2024-05-31 05:38:09] [Error] An error occurred during persistent setstate database operation: cannot commit - no transaction is active
[2024-05-31 05:43:11] [Error] A <class 'sqlite3.OperationalError'> occurred while saving telemetry to database: cannot commit - no transaction is active
[2024-05-31 05:43:11] [Error] Traceback (most recent call last):
  File "c:\users\michael\appdata\local\programs\python\python38\lib\site-packages\sbapp\sideband\core.py", line 1829, in _db_save_telemetry
    db.commit()
sqlite3.OperationalError: cannot commit - no transaction is active

[2024-05-31 05:46:13] [Error] An error occurred during persistent setstate database operation: cannot commit - no transaction is active
[2024-05-31 05:47:13] [Error] An error occurred during persistent setstate database operation: cannot commit - no transaction is active
[2024-05-31 05:50:15] [Error] An error occurred during persistent setstate database operation: cannot commit - no transaction is active
[2024-05-31 05:51:15] [Error] An error occurred during persistent setstate database operation: cannot commit - no transaction is active
[2024-05-31 05:53:16] [Error] An error occurred during persistent setstate database operation: cannot commit - no transaction is active
[2024-05-31 05:54:17] [Error] An error occurred during persistent setstate database operation: cannot start a transaction within a transaction
[2024-05-31 05:54:17] [Error] A <class 'sqlite3.DatabaseError'> occurred while saving telemetry to database: no more rows available
[2024-05-31 05:54:17] [Error] Traceback (most recent call last):
  File "c:\users\michael\appdata\local\programs\python\python38\lib\site-packages\sbapp\sideband\core.py", line 1829, in _db_save_telemetry
    db.commit()
sqlite3.DatabaseError: no more rows available

Some previous highlights:

[2024-05-31 04:56:47] [Error] A <class 'sqlite3.OperationalError'> occurred while saving telemetry to database: cannot commit - no transaction is active
[2024-05-31 04:56:47] [Error] Traceback (most recent call last):
  File "c:\users\michael\appdata\local\programs\python\python38\lib\site-packages\sbapp\sideband\core.py", line 1829, in _db_save_telemetry
    db.commit()
sqlite3.OperationalError: cannot commit - no transaction is active

[2024-05-31 03:06:53] [Error] A <class 'sqlite3.OperationalError'> occurred while saving telemetry to database: cannot commit - no transaction is active
[2024-05-31 03:06:53] [Error] Traceback (most recent call last):
  File "c:\users\michael\appdata\local\programs\python\python38\lib\site-packages\sbapp\sideband\core.py", line 1829, in _db_save_telemetry
    db.commit()
sqlite3.OperationalError: cannot commit - no transaction is active

[2024-05-31 03:08:54] [Error] A <class 'sqlite3.OperationalError'> occurred while saving telemetry to database: not an error
[2024-05-31 03:08:54] [Error] Traceback (most recent call last):
  File "c:\users\michael\appdata\local\programs\python\python38\lib\site-packages\sbapp\sideband\core.py", line 1828, in _db_save_telemetry
    dbc.execute(query, data)
sqlite3.OperationalError: not an error

[2024-05-31 03:11:56] [Error] A <class 'sqlite3.OperationalError'> occurred while saving telemetry to database: not an error
[2024-05-31 03:11:56] [Error] Traceback (most recent call last):
  File "c:\users\michael\appdata\local\programs\python\python38\lib\site-packages\sbapp\sideband\core.py", line 1828, in _db_save_telemetry
    dbc.execute(query, data)
sqlite3.OperationalError: not an error

This may be a race condition, unhandled error, or logic error. Database appears well formed, with 204k telemetry entries and a file size of less than 30 megs. IDs go to 206k but start at 1. This may imply 2,000 lost entries (or ~1%).

I may dig into this further if nothing is obviously wrong.

[markqvist]

Interesting. I'm wondering if this is something that is localised to Windows, since I've never seen it before, and greping through old logfiles yield no results either. I'll keep an eye out for this too.

[faragher]

This was in my console window when opened on Windows. It's possible it's Windows-specific or simply a rate issue with the number of senders I currently have running.

[faragher]

Well this is strange:

[2024-05-31 14:28:52] [Error] A <class 'sqlite3.OperationalError'> occurred while saving telemetry to database: cannot start a transaction within a transaction
[2024-05-31 14:28:52] [Error] Traceback (most recent call last):
  File "c:\users\michael\appdata\local\programs\python\python38\lib\site-packages\sbapp\sideband\core.py", line 1828, in _db_save_telemetry
    dbc.execute(query, data)
sqlite3.OperationalError: cannot start a transaction within a transaction

[2024-05-31 14:30:24] [Error] A <class 'sqlite3.OperationalError'> occurred while saving telemetry to database: cannot commit - no transaction is active
[2024-05-31 14:30:24] [Error] Traceback (most recent call last):
  File "c:\users\michael\appdata\local\programs\python\python38\lib\site-packages\sbapp\sideband\core.py", line 1829, in _db_save_telemetry
    db.commit()
sqlite3.OperationalError: cannot commit - no transaction is active

[2024-05-31 14:30:27] [Error] A <class 'sqlite3.OperationalError'> occurred while saving telemetry to database: cannot commit - no transaction is active
[2024-05-31 14:30:27] [Error] Traceback (most recent call last):
  File "c:\users\michael\appdata\local\programs\python\python38\lib\site-packages\sbapp\sideband\core.py", line 1829, in _db_save_telemetry
    db.commit()
sqlite3.OperationalError: cannot commit - no transaction is active

So, on first attempt it tries to open a transaction within a transaction, then it doesn't have an open transaction? All I can think is somehow sharing the database connection (self.db as used in __db_connect) makes it think it has a pending transaction or otherwise gets out of sync? Isn't the point of SQL is parallelization? Shouldn't a unique cursor be enough? I don't know enough about SQL.

[zirpu]

I think it's reusing a cursor, dbc, that could be the problem. If a new cursor is created, that might be the new transaction it needs.

[markqvist]

I've made some updates to the database code that will hopefully prevent this, and have not been able to replicate it since these fixes. Updated version will be released next week or so. Closing now, but please do re-open or comment if it is observed again.