Hello, I have a problem getting SQLITE_BUSY, and the lock won?t get released.
The problem *seems* to have started around the time we upgraded sqlite from 3.8.10 to 3.9.0, but it's not confirmed. I can?t find anything in our firmware logic which should be relevant to the changed locking behaviour, so it might be something we run into which isn?t intended. The system has 2 main processes, a GUI and a Firmware The GUI process: The Webserver/PHP can process up to 16 requests simultanuously and will share one database connection among all instances. The process for each request is: * Use PHP's PDO extension to open a persistent (shared among all instances) connection to the database -> In the background PHP will only open the database once and then use this connection forever * Each request exectues the following queries initially PRAGMA FOREIGN_KEYS = ON; PRAGMA journal_mode = WAL; PRAGMA busy_timeout = 1000; * Queries are exectued directly without the use of any transactions (as the queries are mostly read queries or only affect one dataset at a time) * If a query fails, due to a busy timeout or locked database (what may occur in situations of high system load) the query is retried 10 times, with a 100ms sleep between the retries * At the end of a request, the database is left open (i.e. no disconnect is done) in order to maintain the persistent database connection The firmware process: * Is running 6 or 18 threads depending on hardware. * Each thread has its own connection to the database. * WAL mode is enabled. * Every time a thread needs to update/insert/delete the call is wrapped inside a queue mechanism, so no more than 1 thread tries to write any changes to the db at the same time. * Every db manipulating action starts with BEGIN IMMEDIATE TRANSACTION. We are unable to find any faults in the logic of the firmware, and logging shows for example: 2016-01-20 17:03:37.034699 [ Thread: 1073824736 ] SQL: BEGIN IMMEDIATE TRANSACTION; 2016-01-20 17:03:37.035218 [ Thread: 1073824736 ] SQL: UPDATE ... 2016-01-20 17:03:37.101044 [ Thread: 1073824736 ] SQL: COMMIT; 2016-01-20 17:03:37.101960 [ Thread: 1094747280 ] SQL: BEGIN IMMEDIATE TRANSACTION; 2016-01-20 17:03:37.102753 [ Thread: 1094747280 ] SQL: UPDATE ... 2016-01-20 17:03:37.175538 [ Thread: 1094747280 ] SQL: COMMIT; 2016-01-20 17:03:37.176636 [ Thread: 1073824736 ] SQL: BEGIN IMMEDIATE TRANSACTION; 2016-01-20 17:03:37.177216 [ Thread: 1073824736 ] SQL: UPDATE ... 2016-01-20 17:03:37.180573 [ Thread: 1094747280 ] SQL: SELECT x... 2016-01-20 17:03:37.182984 [ Thread: 1094747280 ] SQL: SELECT y... 2016-01-20 17:03:37.187806 [ Thread: 1094747280 ] SQL: SELECT z... 2016-01-20 17:03:37.255249 [ Thread: 1073824736 ] SQL: COMMIT; 2016-01-20 17:03:37.256226 [ Thread: 1094747280 ] SQL: BEGIN IMMEDIATE TRANSACTION; 2016-01-20 17:03:37.257447 [ Thread: 1094747280 ] ERROR: Begin transaction failed, adding random delay (96 ms) before retry. Error: SQLITE_BUSY[5]: database is locked 5 2016-01-20 17:03:37.257843 [ Thread: 1073824736 ] SQL: SELECT ... 2016-01-20 17:03:37.354157 [ Thread: 1094747280 ] SQL: BEGIN IMMEDIATE TRANSACTION; 2016-01-20 17:03:37.354889 [ Thread: 1094747280 ] ERROR: Begin transaction failed, adding random delay (65 ms) before retry. Error: SQLITE_BUSY[5]: database is locked 5 2016-01-20 17:03:37.420502 [ Thread: 1094747280 ] SQL: BEGIN IMMEDIATE TRANSACTION; 2016-01-20 17:03:37.421082 [ Thread: 1094747280 ] ERROR: Begin transaction failed, adding random delay (17 ms) before retry. Error: SQLITE_BUSY[5]: database is locked 5 and it will retry forever, since the database will stay in SQLITE_BUSY. (This leads to all other threads getting stuck as soon as they need to update/insert/delete since they'll wait forever for the queue mechanism to give them write access to the database.) Checking in the GUI log, it doesn?t do any insert/delete/update just before the main thread got locked out: 2016-01-20T17:03:34+01:00: Query, try 0: PRAGMA FOREIGN_KEYS = ON; 2016-01-20T17:03:34+01:00: Query, try 0: PRAGMA journal_mode = WAL; 2016-01-20T17:03:34+01:00: Query, try 0: PRAGMA busy_timeout = 1000; 2016-01-20T17:03:34+01:00: Query, try 0: SELECT ... 2016-01-20T17:03:34+01:00: Query, try 0: SELECT ... 2016-01-20T17:03:35+01:00: Query, try 0: PRAGMA FOREIGN_KEYS = ON; 2016-01-20T17:03:35+01:00: Query, try 0: PRAGMA journal_mode = WAL; 2016-01-20T17:03:35+01:00: Query, try 0: PRAGMA busy_timeout = 1000; 2016-01-20T17:03:37+01:00: Query, try 0: SELECT ... 2016-01-20T17:03:38+01:00: Query, try 0: PRAGMA FOREIGN_KEYS = ON; 2016-01-20T17:03:38+01:00: Query, try 0: PRAGMA journal_mode = WAL; 2016-01-20T17:03:38+01:00: Query, try 0: PRAGMA busy_timeout = 1000; 2016-01-20T17:03:38+01:00: Query, try 0: SELECT ... 2016-01-20T17:03:38+01:00: Query, try 0: SELECT ... (I know the PRAGMAs doesn?t need to be set more than once, but we currently do) There are no other processes accessing the database. We haven't been able to reproduce the locking ourselves even when trying to stress test the system, but have received several error reports from customers describing the same situation. Any suggestions how to debug and find the reason why we get SQLITE_BUSY?
