clementgallet / libTAS

GNU/Linux software to (hopefully) give TAS tools to games
GNU General Public License v3.0
476 stars 56 forks source link

SQLite error "attempt to write a readonly database" when "Prevent writing to disk" is turned on #611

Closed SergioFLS closed 1 week ago

SergioFLS commented 2 weeks ago

Tested on latest interim (commit 1a1cfbfc6b750bc237907fad713c4fb330257a7f).

Whenever a game tries to write data via SQLite, it will error out due to an "attempt to write a readonly database", despite that it should write to memory. It works completely fine when "Prevent writing to disk" is turned off, though.

I've only seen this happen on Minetest, but I also hacked together a Python script to show it in action:

# code based off:
# https://pyga.me/docs/
# https://docs.python.org/3/library/sqlite3.html

import pygame
import random
import sqlite3

con = sqlite3.connect('path/to/your/test.db') # replace this
cur = con.cursor()

pygame.init()
screen = pygame.display.set_mode((320, 240))
clock = pygame.time.Clock()
running = True

player_pos = pygame.Vector2(0, 20)
while running:
    for event in pygame.event.get():
        if event.type == pygame.QUIT:
            running = False

    screen.fill('black')

    # "render your game here"

    pygame.draw.circle(screen, 'red', player_pos, 20)

    player_pos.x += 1
    if player_pos.x == 5:
        cur.execute("INSERT INTO test VALUES (?)", [str(random.randint(0, 255))])
        con.commit()
        print('passed!')
        print(cur.execute('SELECT * FROM test').fetchall())

    # flip
    pygame.display.flip()

    clock.tick(60)

pygame.quit()

Extract test.db.zip and edit the code above to make it point to the extracted test.db. You'll also need pygame-ce to run it.

Running the code for five frames it will try add some data into the database file. When it succeeds, it should log into the terminal something like this:

passed!
[('219',)]

On LibTAS, with "Prevent writing to disk" turned on however:

Traceback (most recent call last):
  File "/home/sergio/Documentos/pygamecetesting/sqlitest.py", line 27, in <module>
    cur.execute("INSERT INTO test VALUES (?)", [str(random.randint(0, 255))])
sqlite3.OperationalError: attempt to write a readonly database
clementgallet commented 2 weeks ago

Useful log from strace (without libtas)

openat(AT_FDCWD, "/home/clement/Games/pysql/test.db", O_RDWR|O_CREAT|O_NOFOLLOW|O_CLOEXEC, 0644) = 3
newfstatat(3, "", {st_mode=S_IFREG|0644, st_size=8192, ...}, AT_EMPTY_PATH) = 0
newfstatat(3, "", {st_mode=S_IFREG|0644, st_size=8192, ...}, AT_EMPTY_PATH) = 0
newfstatat(AT_FDCWD, "/home/clement/Games/pysql/test.db", {st_mode=S_IFREG|0644, st_size=8192, ...}, 0) = 0
pread64(3, "SQLite format 3\0\20\0\1\1\0@  \0\0\0\3\0\0\0\2"..., 100, 0) = 100

...

fcntl(3, F_SETLK, {l_type=F_RDLCK, l_whence=SEEK_SET, l_start=1073741824, l_len=1}) = 0
fcntl(3, F_SETLK, {l_type=F_RDLCK, l_whence=SEEK_SET, l_start=1073741826, l_len=510}) = 0
fcntl(3, F_SETLK, {l_type=F_UNLCK, l_whence=SEEK_SET, l_start=1073741824, l_len=1}) = 0
newfstatat(3, "", {st_mode=S_IFREG|0644, st_size=8192, ...}, AT_EMPTY_PATH) = 0
pread64(3, "SQLite format 3\0\20\0\1\1\0@  \0\0\0\3\0\0\0\2"..., 4096, 0) = 4096
fcntl(3, F_SETLK, {l_type=F_UNLCK, l_whence=SEEK_SET, l_start=0, l_len=0}) = 0
fcntl(3, F_SETLK, {l_type=F_RDLCK, l_whence=SEEK_SET, l_start=1073741824, l_len=1}) = 0
fcntl(3, F_SETLK, {l_type=F_RDLCK, l_whence=SEEK_SET, l_start=1073741826, l_len=510}) = 0
fcntl(3, F_SETLK, {l_type=F_UNLCK, l_whence=SEEK_SET, l_start=1073741824, l_len=1}) = 0
pread64(3, "\0\0\0\3\0\0\0\2\0\0\0\0\0\0\0\0", 16, 24) = 16
newfstatat(3, "", {st_mode=S_IFREG|0644, st_size=8192, ...}, AT_EMPTY_PATH) = 0
fcntl(3, F_SETLK, {l_type=F_WRLCK, l_whence=SEEK_SET, l_start=1073741825, l_len=1}) = 0
pread64(3, "\r\0\0\0\2\17\362\0\17\371\17\362\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 4096, 4096) = 4096
newfstatat(AT_FDCWD, "/home/clement/Games/pysql/test.db", {st_mode=S_IFREG|0644, st_size=8192, ...}, 0) = 0
newfstatat(AT_FDCWD, "/home/clement/Games/pysql/test.db", {st_mode=S_IFREG|0644, st_size=8192, ...}, 0) = 0
fcntl(3, F_SETLK, {l_type=F_WRLCK, l_whence=SEEK_SET, l_start=1073741824, l_len=1}) = 0
fcntl(3, F_SETLK, {l_type=F_WRLCK, l_whence=SEEK_SET, l_start=1073741826, l_len=510}) = 0
pwrite64(3, "SQLite format 3\0\20\0\1\1\0@  \0\0\0\4\0\0\0\2"..., 4096, 0) = 4096
pwrite64(3, "\r\0\0\0\3\17\353\0\17\371\17\362\17\353\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 4096, 4096) = 4096
fdatasync(3)                            = 0
fcntl(3, F_SETLK, {l_type=F_RDLCK, l_whence=SEEK_SET, l_start=1073741826, l_len=510}) = 0
fcntl(3, F_SETLK, {l_type=F_UNLCK, l_whence=SEEK_SET, l_start=1073741824, l_len=2}) = 0
fcntl(3, F_SETLK, {l_type=F_UNLCK, l_whence=SEEK_SET, l_start=0, l_len=0}) = 0
write(1, "passed!\n", 8)                = 8
fcntl(3, F_SETLK, {l_type=F_RDLCK, l_whence=SEEK_SET, l_start=1073741824, l_len=1}) = 0
fcntl(3, F_SETLK, {l_type=F_RDLCK, l_whence=SEEK_SET, l_start=1073741826, l_len=510}) = 0
fcntl(3, F_SETLK, {l_type=F_UNLCK, l_whence=SEEK_SET, l_start=1073741824, l_len=1}) = 0
clementgallet commented 2 weeks ago

From within libTAS. The difference in the beginning is libtas code: use memfd_create() to obtain a file descriptor, open the real file and copy to the memfd using sendfile()

memfd_create("/home/clement/Games/pysql/test.d"..., 0) = 3
newfstatat(AT_FDCWD, "/home/clement/Games/pysql/test.db", {st_mode=S_IFREG|0644, st_size=8192, ...}, 0) = 0 
openat(AT_FDCWD, "/home/clement/Games/pysql/test.db", O_RDONLY) = 5
ftruncate(3, 8192)                      = 0
sendfile(3, 5, [0] => [8192], 8192)     = 8192
close(5)                                = 0
lseek(3, 0, SEEK_SET)                   = 0
newfstatat(3, "", {st_mode=S_IFREG|0777, st_size=8192, ...}, AT_EMPTY_PATH) = 0
newfstatat(3, "", {st_mode=S_IFREG|0777, st_size=8192, ...}, AT_EMPTY_PATH) = 0
pread64(3, "SQLite format 3\0\20\0\1\1\0@  \0\0\0\5\0\0\0\2"..., 100, 0) = 100

...

fcntl(3, F_SETLK, {l_type=F_RDLCK, l_whence=SEEK_SET, l_start=1073741824, l_len=1}) = 0
fcntl(3, F_SETLK, {l_type=F_RDLCK, l_whence=SEEK_SET, l_start=1073741826, l_len=510}) = 0
fcntl(3, F_SETLK, {l_type=F_UNLCK, l_whence=SEEK_SET, l_start=1073741824, l_len=1}) = 0
newfstatat(3, "", {st_mode=S_IFREG|0777, st_size=8192, ...}, AT_EMPTY_PATH) = 0
pread64(3, "SQLite format 3\0\20\0\1\1\0@  \0\0\0\5\0\0\0\2"..., 4096, 0) = 4096
fcntl(3, F_SETLK, {l_type=F_UNLCK, l_whence=SEEK_SET, l_start=0, l_len=0}) = 0
fcntl(3, F_SETLK, {l_type=F_RDLCK, l_whence=SEEK_SET, l_start=1073741824, l_len=1}) = 0
fcntl(3, F_SETLK, {l_type=F_RDLCK, l_whence=SEEK_SET, l_start=1073741826, l_len=510}) = 0
fcntl(3, F_SETLK, {l_type=F_UNLCK, l_whence=SEEK_SET, l_start=1073741824, l_len=1}) = 0
pread64(3, "\0\0\0\5\0\0\0\2\0\0\0\0\0\0\0\0", 16, 24) = 16
newfstatat(3, "", {st_mode=S_IFREG|0777, st_size=8192, ...}, AT_EMPTY_PATH) = 0
fcntl(3, F_SETLK, {l_type=F_WRLCK, l_whence=SEEK_SET, l_start=1073741825, l_len=1}) = 0
pread64(3, "\r\0\0\0\4\17\344\0\17\371\17\362\17\353\17\344\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 4096, 4096) = 4096
newfstatat(AT_FDCWD, "/home/clement/Games/pysql/test.db", {st_mode=S_IFREG|0644, st_size=8192, ...}, 0) = 0
write(2, "Traceback (most recent call last"..., 35Traceback (most recent call last):
) = 35
write(2, "  File \"/home/clement/Games/pysq"..., 65  File "/home/clement/Games/pysql/test.py", line 31, in <module>
) = 65
clementgallet commented 2 weeks ago

The error correspond to error code SQLITE_READONLY which can be found for example in this code: https://github.com/sqlite/sqlite/blob/709cb313cf7b2da986ec2c0ca6510147ac702538/src/os_unix.c#L4957

CasualPokePlayer commented 1 week ago

Here's a more simple test

#include <sqlite3.h>
#include <stdio.h>
#include <unistd.h>

int main(void)
{
    sqlite3* db;
    if (sqlite3_open("test.db", &db) != SQLITE_OK)
    {
        return -1;
    }

    sqlite3_stmt* stmt = NULL;
    int rc = sqlite3_prepare_v2(db, "CREATE TABLE thingy (stuff NUMBER)", -1, &stmt, NULL);
    fprintf(stderr, "sqlite3_prepare_v2: %d, %s, %d\n", rc, sqlite3_errmsg(db), sqlite3_stmt_readonly(stmt));
    if (rc == SQLITE_OK)
    {
        sleep(20);
        rc = sqlite3_step(stmt);
        sleep(60);
        fprintf(stderr, "sqlite3_step %d, %s\n", rc, sqlite3_errmsg(db));
        rc = sqlite3_finalize(stmt);
        fprintf(stderr, "sqlite3_finalize %d, %s\n", rc, sqlite3_errmsg(db));
    }

    sqlite3_close(db);
}

sqlite3_step appears to be the call which triggers the error (sleep calls put around it to give time to attach strace).

Using it in particular I saw this with libTAS:

fcntl(3, F_SETLK, {l_type=F_RDLCK, l_whence=SEEK_SET, l_start=1073741824, l_len=1}) = 0
fcntl(3, F_SETLK, {l_type=F_RDLCK, l_whence=SEEK_SET, l_start=1073741826, l_len=510}) = 0
fcntl(3, F_SETLK, {l_type=F_UNLCK, l_whence=SEEK_SET, l_start=1073741824, l_len=1}) = 0
newfstatat(AT_FDCWD, "/home/wesley/test/sqlite_test/test.db-journal", 0x7ffe3791ee50, 0) = -1 ENOENT (No such file or directory)
pread64(3, "", 16, 24)                  = 0
newfstatat(AT_FDCWD, "/home/wesley/test/sqlite_test/test.db-wal", 0x7ffe3791ee50, 0) = -1 ENOENT (No such file or directory)
newfstatat(3, "", {st_mode=S_IFREG|0777, st_size=0, ...}, AT_EMPTY_PATH) = 0
fcntl(3, F_SETLK, {l_type=F_WRLCK, l_whence=SEEK_SET, l_start=1073741825, l_len=1}) = 0
getpid()                                = 1811
newfstatat(AT_FDCWD, "/home/wesley/test/sqlite_test/test.db", 0x7ffe3791ea10, 0) = -1 ENOENT (No such file or directory)
fcntl(3, F_SETLK, {l_type=F_RDLCK, l_whence=SEEK_SET, l_start=1073741826, l_len=510}) = 0
fcntl(3, F_SETLK, {l_type=F_UNLCK, l_whence=SEEK_SET, l_start=1073741824, l_len=2}) = 0
fcntl(3, F_SETLK, {l_type=F_UNLCK, l_whence=SEEK_SET, l_start=0, l_len=0}) = 0

compared to native execution:

fcntl(3, F_SETLK, {l_type=F_RDLCK, l_whence=SEEK_SET, l_start=1073741824, l_len=1}) = 0
fcntl(3, F_SETLK, {l_type=F_RDLCK, l_whence=SEEK_SET, l_start=1073741826, l_len=510}) = 0
fcntl(3, F_SETLK, {l_type=F_UNLCK, l_whence=SEEK_SET, l_start=1073741824, l_len=1}) = 0
newfstatat(AT_FDCWD, "/home/wesley/test/sqlite_test/test.db-journal", 0x7ffc54072d30, 0) = -1 ENOENT (No such file or directory)
pread64(3, "", 16, 24)                  = 0
newfstatat(AT_FDCWD, "/home/wesley/test/sqlite_test/test.db-wal", 0x7ffc54072d30, 0) = -1 ENOENT (No such file or directory)
newfstatat(3, "", {st_mode=S_IFREG|0644, st_size=0, ...}, AT_EMPTY_PATH) = 0
fcntl(3, F_SETLK, {l_type=F_WRLCK, l_whence=SEEK_SET, l_start=1073741825, l_len=1}) = 0
getpid()                                = 1839
newfstatat(AT_FDCWD, "/home/wesley/test/sqlite_test/test.db", {st_mode=S_IFREG|0644, st_size=0, ...}, 0) = 0
openat(AT_FDCWD, "/home/wesley/test/sqlite_test/test.db-journal", O_RDWR|O_CREAT|O_NOFOLLOW|O_CLOEXEC, 0644) = 4
newfstatat(4, "", {st_mode=S_IFREG|0644, st_size=0, ...}, AT_EMPTY_PATH) = 0
geteuid()                               = 1000
getpid()                                = 1839
openat(AT_FDCWD, "/dev/urandom", O_RDONLY|O_CLOEXEC) = 5
read(5, "\325\301\232/j\237\251r?0\2075\212\304\262\243\315\255\206\205\377$\210\315\236f\3\363\7\360o\215"..., 256) = 256
close(5)                                = 0
pwrite64(4, "\0\0\0\0\0\0\0\0\0\0\0\0\272\373(?\0\0\0\0\0\0\2\0\0\0\20\0\0\0\0\0"..., 512, 0) = 512
fcntl(3, F_SETLK, {l_type=F_WRLCK, l_whence=SEEK_SET, l_start=1073741824, l_len=1}) = 0
fcntl(3, F_SETLK, {l_type=F_WRLCK, l_whence=SEEK_SET, l_start=1073741826, l_len=510}) = 0
pread64(4, "", 8, 512)                  = 0
fdatasync(4)                            = 0
openat(AT_FDCWD, "/home/wesley/test/sqlite_test", O_RDONLY|O_CLOEXEC) = 5
fdatasync(5)                            = 0
close(5)                                = 0
pwrite64(4, "\331\325\5\371 \241c\327\0\0\0\0", 12, 0) = 12
fdatasync(4)                            = 0
pwrite64(3, "SQLite format 3\0\20\0\1\1\0@  \0\0\0\1\0\0\0\2"..., 4096, 0) = 4096
pwrite64(3, "\r\0\0\0\0\20\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 4096, 4096) = 4096
fdatasync(3)                            = 0
close(4)                                = 0
unlink("/home/wesley/test/sqlite_test/test.db-journal") = 0
fcntl(3, F_SETLK, {l_type=F_RDLCK, l_whence=SEEK_SET, l_start=1073741826, l_len=510}) = 0
fcntl(3, F_SETLK, {l_type=F_UNLCK, l_whence=SEEK_SET, l_start=1073741824, l_len=2}) = 0
fcntl(3, F_SETLK, {l_type=F_UNLCK, l_whence=SEEK_SET, l_start=0, l_len=0}) = 0

newfstatat(AT_FDCWD, "/home/wesley/test/sqlite_test/test.db", 0x7ffe3791ea10, 0) = -1 ENOENT (No such file or directory) particularly looks problematic (and seems to be the diverging point). This is without having an actual file in place anyways (so the code is supposed to "create" a new file). If I put in an empty test.db file the code ends up running successfully.

clementgallet commented 1 week ago

Thanks for the added code. The issue was that newer glibc version changed the aliases for the stat/lstat/fstat functions. The real functions were named __xstat() and such, and now the public name is the same as the underlying symbol. Because of that, libTAS was not hooking any of the stat functions, and failed to report the correct stat() result for savefiles.