Requests to SQLite3 databases do not wait for the lock, causing errors on simultaneous access #206

New Issue

ChristopherCormier · 2021-04-22T10:12:31Z

2021-04-22 10:12:31 +00:00

This can be trivially reproduced by trying to submit two posts at the same time to a board, but it can happen commonly out in the wild on any board that has a high likelihood of two people trying to submit something at once.

The largest issue here is that, from a user's perspective, the post looks like it should've succeeded but it doesn't, and they lose everything that they've typed.

"Silently" isn't entirely true, as it does produce three warnings that are visible for a small fraction of a second in the same screen where it updates the thread and index, though it goes by so quickly that it'd be impossible for a user to understand it, and unintelligible even if they did: https://i.imgur.com/iUtTiuq.png

Though not thoroughly tested, this problem should also reasonably affect any and all database operations when using SQLite3, preventing anything from happening concurrently. Notably, accessing the management panel at the same time as someone is making a post causes an error in the management panel as well. I'm suspecting that the reverse is also true, that accessing the management panel would block someone's post if it was timed right.

My basic impression is that the optimal way to fix this would be to raise the SQLite busy timeout value so that other requests will properly wait on the lock to close, "queueing" for it instead of immediately erroring out. Let me know if I'm misunderstanding anything.

This can be trivially reproduced by trying to submit two posts at the same time to a board, but it can happen commonly out in the wild on any board that has a high likelihood of two people trying to submit something at once. The largest issue here is that, from a user's perspective, the post looks like it should've succeeded but it doesn't, and they lose everything that they've typed. "Silently" isn't *entirely* true, as it does produce three warnings that are visible for a small fraction of a second in the same screen where it updates the thread and index, though it goes by so quickly that it'd be impossible for a user to understand it, and unintelligible even if they did: https://i.imgur.com/iUtTiuq.png Though not thoroughly tested, this problem should also reasonably affect any and all database operations when using SQLite3, preventing anything from happening concurrently. Notably, accessing the management panel at the same time as someone is making a post causes an error in the management panel as well. I'm suspecting that the reverse is also true, that accessing the management panel would block someone's post if it was timed right. My basic impression is that the optimal way to fix this would be to raise the SQLite busy timeout value so that other requests will properly wait on the lock to close, "queueing" for it instead of immediately erroring out. Let me know if I'm misunderstanding anything.

ChristopherCormier commented

2021-04-22 10:32:38 +00:00

Small follow-up: I think I've been able to reproduce this simply from deleting two posts separately in relatively quick succession (7-10 seconds between). There's a decently powerful server backing my instance with no other activity outside of testing. It seems like the lock is lasting longer than is reasonable, especially with the tiny size of the database and the triviality of the database operation. Is it waiting on something else before it closes?

tslocum added the

bug

label 2021-04-22 23:24:20 +00:00

tslocum referenced this issue from a commit

2021-04-23 04:10:17 +00:00

Set SQLite3 database timout to one minute

tslocum closed this issue

2021-04-23 04:10:17 +00:00

tslocum commented

2021-04-23 04:10:26 +00:00

Thanks for reporting this.

ChristopherCormier commented

2021-08-03 21:45:54 +00:00

Reopening for now, as it seems like this has been happening again when my board's at peak hours of activity. Bewilderingly, this includes moments when no posts are even being made, but the board is being accessed a lot.

Anecdotally, it seems like it happens much more frequently when TINYIB_AUTOREFRESH is set to a very low value, but I don't know if that makes sense. It also tends to happen when navigating through the moderation section, presumably from the lastactive value being updated for staff accounts in the database on each page load.

The most common error I've seen lately is:
PHP Warning: SQLite3::exec(): database is locked in /var/www/html/inc/database/sqlite3.php on line 4
But the line number has been almost anything, especially including lines 15, 17, 19, and 33 recently. I've had user reports of this error occasionally eating posts as well, and it's possibly connected to some other issues I've experienced (such as threads sometimes only partially generating, creating a listing on the board index and catalog but without creating an associated res/X.html file).

I don't know if there's any good way for me to test or diagnose the cause of this. If I query the setting in the database with PRAGMA busy_timeout;, it claims to be set to 0 instead of the expected 60000, but I don't know if that has any actual relation to the timeout that's being set in sqlite3_link.php

Reopening for now, as it seems like this has been happening again when my board's at peak hours of activity. Bewilderingly, this includes moments when no posts are even being made, but the board is being accessed a lot. Anecdotally, it seems like it happens *much* more frequently when TINYIB_AUTOREFRESH is set to a very low value, but I don't know if that makes sense. It also tends to happen when navigating through the moderation section, presumably from the lastactive value being updated for staff accounts in the database on each page load. The most common error I've seen lately is: `PHP Warning: SQLite3::exec(): database is locked in /var/www/html/inc/database/sqlite3.php on line 4` But the line number has been almost anything, especially including lines 15, 17, 19, and 33 recently. I've had user reports of this error occasionally eating posts as well, and it's possibly connected to some other issues I've experienced (such as threads sometimes only partially generating, creating a listing on the board index and catalog but without creating an associated res/X.html file). I don't know if there's any good way for me to test or diagnose the cause of this. If I query the setting in the database with `PRAGMA busy_timeout;`, it claims to be set to 0 instead of the expected 60000, but I don't know if that has any actual relation to the timeout that's being set in sqlite3_link.php

👍 1

ChristopherCormier reopened this issue

2021-08-03 21:45:54 +00:00

tslocum commented

2021-08-05 17:03:11 +00:00

Please try 5d191f3513 from the sqlitefix branch, which enables write-ahead logging.

Please try 5d191f351316793c4b31a3819ddd7bc29cfae41c from the sqlitefix branch, which enables [write-ahead logging](https://www.sqlite.org/wal.html).

tslocum commented

2021-08-05 17:08:12 +00:00

Also, please try replacing this line

$db->busyTimeout(60000);

with

$db->exec("PRAGMA busy_timeout = 60000");

and let me know if busy_timeout is updated.

Also, please try replacing this line `$db->busyTimeout(60000);` with `$db->exec("PRAGMA busy_timeout = 60000");` and let me know if `busy_timeout` is updated.

ChristopherCormier commented

2021-09-15 10:20:52 +00:00

Sorry for the long wait, I only just now got around to adopting those fixes. I've replaced that line in my sqlite3_link.php file with $db->exec("PRAGMA busy_timeout = 60000"); and $db->exec("PRAGMA journal_mode = wal"); as shown here: https://i.imgur.com/9d5D416.png

Time will tell if this fixes the problem, but I'll note that querying busy_timeout through the interactive shell still returns 0, even after TinyIB has modified the database with this new code added.

That said, perhaps this issue stems from my inexperience with SQL. Even if I copy the database to a separate file that's unmanaged by TinyIB, manually run PRAGMA busy_timeout = 60000; on it, confirm it saved by querying the pragma immediately after, and then save and exit the database, the value has reset whenever I freshly open it again.

Is this pragma value meant to be persistently stored in the database after being set? Or is it only remembered as long as your connection with the database remains open? I suspect I'm doing something wrong.

Sorry for the long wait, I only just now got around to adopting those fixes. I've replaced that line in my sqlite3_link.php file with `$db->exec("PRAGMA busy_timeout = 60000");` and `$db->exec("PRAGMA journal_mode = wal");` as shown here: https://i.imgur.com/9d5D416.png Time will tell if this fixes the problem, but I'll note that querying busy_timeout through the interactive shell still returns `0`, even after TinyIB has modified the database with this new code added. That said, perhaps this issue stems from my inexperience with SQL. Even if I copy the database to a separate file that's unmanaged by TinyIB, manually run `PRAGMA busy_timeout = 60000;` on it, confirm it saved by querying the pragma immediately after, and then save and exit the database, the value has reset whenever I freshly open it again. Is this pragma value meant to be persistently stored in the database after being set? Or is it only remembered as long as your connection with the database remains open? I suspect I'm doing something wrong.

ChristopherCormier commented

2021-10-05 20:50:34 +00:00

Update: Doesn't seem to have made a difference unfortunately. During another spike of activity, my error.log saw a sizable number of "PHP Warning: SQLite3::exec(): database is locked in [...]/inc/database/sqlite3.php on line 4" entries.

Worth noting that "PRAGMA journal_mode;" does print wal now, but "PRAGMA busy_timeout;" continues printing 0

Update: Doesn't seem to have made a difference unfortunately. During another spike of activity, my error.log saw a sizable number of "PHP Warning: SQLite3::exec(): database is locked in [...]/inc/database/sqlite3.php on line 4" entries. Worth noting that "PRAGMA journal_mode;" *does* print `wal` now, but "PRAGMA busy_timeout;" continues printing `0`

tslocum commented

2021-10-06 01:32:02 +00:00

Thanks. I will look into this more when I have some time. If this is being caused by a race condition, #251 should fix this.

👍 1

tslocum commented

2022-04-08 23:29:35 +00:00

Please let me know whether this was indeed fixed by #251 (which I've just implemented).

ChristopherCormier commented

2022-05-27 13:29:51 +00:00

My boards have been less active anyways lately so I can't say for sure, but I haven't had any instances of this error since pulling in 57b50658a2 a couple months ago. I'll close this for now and assume it's fixed. Thank you for your work as always!

My boards have been less active anyways lately so I can't say for sure, but I haven't had any instances of this error since pulling in 57b50658a2 a couple months ago. I'll close this for now and assume it's fixed. Thank you for your work as always!

ChristopherCormier closed this issue

2022-05-27 13:29:51 +00:00

alix commented

2022-07-16 09:04:40 +00:00

This issue is still a thing on sqlite3!
Im on latest master branch with patch from sqlitefix branch (php-sqlite3 7.4-30)
And this still happens... way more rarely after enabling WAL mode but it happens, is terribly annoying

To end users behavior is just as explained in first post

The largest issue here is that, from a user's perspective, the post looks like it should've succeeded but it doesn't, and they lose everything that they've typed.

@tslocum any futher ideas?

This issue is still a thing on sqlite3! Im on latest master branch with patch from sqlitefix branch (php-sqlite3 7.4-30) And this still happens... way more rarely after enabling WAL mode but it happens, is terribly annoying To end users behavior is just as explained in first post > The largest issue here is that, from a user's perspective, the post looks like it should've succeeded but it doesn't, and they lose everything that they've typed. @tslocum any futher ideas?

tslocum commented

2022-07-19 17:44:17 +00:00

@alix, please share which operating system you are using. I don't believe you need to apply any patches to TinyIB or PHP to get this to work, you should be able to use a standard release of both. Once you've confirmed these details I will reopen this issue.

alix commented

2022-07-22 10:18:40 +00:00

by patch I've meant this commit 5d191f3513
OS is debian 11 bullseye with 5.10.x kernel
Im using standard version of php7.4 and php-sqlite3 from debian repo
Like I said this error happens really really rarely now but still...

by patch I've meant this commit https://code.rocketnine.space/tslocum/tinyib/commit/5d191f351316793c4b31a3819ddd7bc29cfae41c OS is debian 11 bullseye with 5.10.x kernel Im using standard version of php7.4 and php-sqlite3 from debian repo Like I said this error happens really really rarely now but still...

tslocum commented

2022-07-25 19:49:23 +00:00

That branch should no longer be needed, because of 57b50658a2. Please update to the latest commit in the master branch, and let me know if you still encounter this.

That branch should no longer be needed, because of 57b50658a2b306244047e686212dbe3ffce3a6e6. Please update to the latest commit in the master branch, and let me know if you still encounter this.

alix commented

2022-07-27 14:17:13 +00:00

Im on latest master branch all the time since my first post
(just took that commit from sqlitefix branch and applyed it on my own because I faced issues...)

picrel is unrelated to posting issue but still probably shoudnt be that way at all...

Im on latest master branch all the time since my first post (just took that commit from sqlitefix branch and applyed it on my own because I faced issues...) ![](https://i.ibb.co/xMNNzfb/lock.png) picrel is unrelated to posting issue but still probably shoudnt be that way at all...

tslocum commented

2022-07-28 22:15:18 +00:00

You shouldn't need to apply the commit in the sqlitefix branch. Please reset your repository to not include this commit. If you are still encountering issues, ensure TINYIB_LOCKFILE is set to some value. You could check this by temporarily replacing lockDatabase with the following:

function lockDatabase() {
        if (TINYIB_LOCKFILE == '') {
                fancyDie('TINYIB_LOCKFILE is not set to anything.  Lock file is disabled.');
                return true;
        }
        $fp = fopen(TINYIB_LOCKFILE, 'c+');
        if (!flock($fp, LOCK_EX)) {
                fancyDie('Failed to lock control file.');
        }
        return $fp;
}

You shouldn't need to apply the commit in the sqlitefix branch. Please reset your repository to not include this commit. If you are still encountering issues, ensure `TINYIB_LOCKFILE` is set to some value. You could check this by temporarily replacing `lockDatabase` with the following: ```php function lockDatabase() { if (TINYIB_LOCKFILE == '') { fancyDie('TINYIB_LOCKFILE is not set to anything. Lock file is disabled.'); return true; } $fp = fopen(TINYIB_LOCKFILE, 'c+'); if (!flock($fp, LOCK_EX)) { fancyDie('Failed to lock control file.'); } return $fp; } ```

Thomas commented

2022-07-30 20:17:48 +00:00

hi

we seem to be having some strange bug with the text formating

any suggestions?

hi we seem to be having some strange bug with the text formating any suggestions?

strange text bug.png

30 KiB

alix commented

2022-08-05 09:00:48 +00:00

@tslocum

You shouldn't need to apply the commit in the sqlitefix branch. Please reset your repository to not include this commit.

I understand tho like I said it seems improve stuff overall. And since I faced this issue before applying that commit... reverting it wont fix issue for sure
I've replaced lockDatabase() function with code you have posted and saw no 'fancydeath' on posting so I assume lock file is working fine
when I put fancyDie(TINYIB_LOCKFILE); at very begining of lock function it says

tinyib.lock

such file exists on main imageboard directory all the time

Which of other database modes you recomend?
Im thinking in terms of minimal size and minimal amount of additional packages needed to be installed.
Sqlite3 file based database feels perfect for this meaning but this strange issue...

@Thomas
While this should be in another issue ticket its true
This sort of characters can bypass message framebox and expand beyond (while they shoudn't)

@tslocum >You shouldn't need to apply the commit in the sqlitefix branch. Please reset your repository to not include this commit. I understand tho like I said it seems improve stuff overall. And since I faced this issue before applying that commit... reverting it wont fix issue for sure I've replaced lockDatabase() function with code you have posted and saw no 'fancydeath' on posting so I assume lock file is working fine when I put fancyDie(TINYIB_LOCKFILE); at very begining of lock function it says >tinyib.lock such file exists on main imageboard directory all the time Which of other database modes you recomend? Im thinking in terms of minimal size and minimal amount of additional packages needed to be installed. Sqlite3 file based database feels perfect for this meaning but this strange issue... @Thomas While this should be in another issue ticket its true This sort of characters can bypass message framebox and expand beyond (while they shoudn't)

Sign in to join this conversation.