Hi everyone, I'm working on an open source project that uses sqlite. We use sqlite as a key-value store (as one of multiple possible backends). See https://conduit.rs we also have a matrix room at https://matrix.to/#/#conduit:fachschaften.org https://gitlab.com/famedly/conduit/-/blob/next/src/database/abstraction/sqlite.rs#L51 This is the main file that interacts with sqlite (through the rusqlite rust library). Unfortunately sqlite seems to be very slow when we make many small requests in a row. My small server becomes unusable because of very high IO read. Ram usage also seems higher than expected, which may or may not be sqlite's fault. I would be very grateful if someone could help to improve the situation. I'm happy to answer questions or explain code here or on matrix. Analysing the program gives these logs: ```text 611680 19:23:44.438807703 0 rocket-worker-t (11532) > write fd=10(<f>/srv/conduit/.local/share/conduit/conduit.db-wal) size=2048 611683 19:23:44.438812703 0 rocket-worker-t (11532) > write fd=10(<f>/srv/conduit/.local/share/conduit/conduit.db-wal) size=24 611686 19:23:44.438815303 0 rocket-worker-t (11532) > write fd=10(<f>/srv/conduit/.local/share/conduit/conduit.db-wal) size=2048 611846 19:23:44.439135824 0 rocket-worker-t (11532) > write fd=10(<f>/srv/conduit/.local/share/conduit/conduit.db-wal) size=24 611849 19:23:44.439139524 0 rocket-worker-t (11532) > write fd=10(<f>/srv/conduit/.local/share/conduit/conduit.db-wal) size=2048 611852 19:23:44.439144024 0 rocket-worker-t (11532) > write fd=10(<f>/srv/conduit/.local/share/conduit/conduit.db-wal) size=24 611855 19:23:44.439146524 0 rocket-worker-t (11532) > write fd=10(<f>/srv/conduit/.local/share/conduit/conduit.db-wal) size=2048 612015 19:23:44.439459344 0 rocket-worker-t (11532) > write fd=10(<f>/srv/conduit/.local/share/conduit/conduit.db-wal) size=24 612018 19:23:44.439463044 0 rocket-worker-t (11532) > write fd=10(<f>/srv/conduit/.local/share/conduit/conduit.db-wal) size=2048 612021 19:23:44.439467845 0 rocket-worker-t (11532) > write fd=10(<f>/srv/conduit/.local/share/conduit/conduit.db-wal) size=24 612024 19:23:44.439470445 0 rocket-worker-t (11532) > write fd=10(<f>/srv/conduit/.local/share/conduit/conduit.db-wal) size=2048 612181 19:23:44.439794765 0 rocket-worker-t (11532) > write fd=10(<f>/srv/conduit/.local/share/conduit/conduit.db-wal) size=24 612184 19:23:44.439799966 0 rocket-worker-t (11532) > write fd=10(<f>/srv/conduit/.local/share/conduit/conduit.db-wal) size=2048 612187 19:23:44.439805266 0 rocket-worker-t (11532) > write fd=10(<f>/srv/conduit/.local/share/conduit/conduit.db-wal) size=24 612190 19:23:44.439807966 0 rocket-worker-t (11532) > write fd=10(<f>/srv/conduit/.local/share/conduit/conduit.db-wal) size=2048 612350 19:23:44.440108185 0 rocket-worker-t (11532) > write fd=10(<f>/srv/conduit/.local/share/conduit/conduit.db-wal) size=24 612353 19:23:44.440111786 0 rocket-worker-t (11532) > write fd=10(<f>/srv/conduit/.local/share/conduit/conduit.db-wal) size=2048 612356 19:23:44.440116986 0 rocket-worker-t (11532) > write fd=10(<f>/srv/conduit/.local/share/conduit/conduit.db-wal) size=24 612359 19:23:44.440119686 0 rocket-worker-t (11532) > write fd=10(<f>/srv/conduit/.local/share/conduit/conduit.db-wal) size=2048 612510 19:23:44.440412305 0 rocket-worker-t (11532) > write fd=10(<f>/srv/conduit/.local/share/conduit/conduit.db-wal) size=24 612513 19:23:44.440416105 0 rocket-worker-t (11532) > write fd=10(<f>/srv/conduit/.local/share/conduit/conduit.db-wal) size=2048 612516 19:23:44.440422105 0 rocket-worker-t (11532) > write fd=10(<f>/srv/conduit/.local/share/conduit/conduit.db-wal) size=24 ``` lot's of small 2K chunks written to WAL and then flushed into database file... first 24B then 2K that's the pattern here ``` 2907642 19:26:26.867277520 0 rocket-worker-t (11532) > write fd=9(<f>/srv/conduit/.local/share/conduit/conduit.db) size=2048 2907648 19:26:26.867284521 0 rocket-worker-t (11532) > write fd=9(<f>/srv/conduit/.local/share/conduit/conduit.db) size=2048 2907654 19:26:26.867291321 0 rocket-worker-t (11532) > write fd=9(<f>/srv/conduit/.local/share/conduit/conduit.db) size=2048 2907660 19:26:26.867296821 0 rocket-worker-t (11532) > write fd=9(<f>/srv/conduit/.local/share/conduit/conduit.db) size=2048 2907666 19:26:26.867302822 0 rocket-worker-t (11532) > write fd=9(<f>/srv/conduit/.local/share/conduit/conduit.db) size=2048 2907672 19:26:26.867308822 0 rocket-worker-t (11532) > write fd=9(<f>/srv/conduit/.local/share/conduit/conduit.db) size=2048 2907678 19:26:26.867315223 0 rocket-worker-t (11532) > write fd=9(<f>/srv/conduit/.local/share/conduit/conduit.db) size=2048 2907684 19:26:26.867322123 0 rocket-worker-t (11532) > write fd=9(<f>/srv/conduit/.local/share/conduit/conduit.db) size=2048 2907690 19:26:26.867328423 0 rocket-worker-t (11532) > write fd=9(<f>/srv/conduit/.local/share/conduit/conduit.db) size=2048 2907696 19:26:26.867334224 0 rocket-worker-t (11532) > write fd=9(<f>/srv/conduit/.local/share/conduit/conduit.db) size=2048 2907702 19:26:26.867340124 0 rocket-worker-t (11532) > write fd=9(<f>/srv/conduit/.local/share/conduit/conduit.db) size=2048 2907708 19:26:26.867351725 0 rocket-worker-t (11532) > write fd=9(<f>/srv/conduit/.local/share/conduit/conduit.db) size=2048 ``` That's the syscall pattern for the database file... guess the WAL chunks will be moved to database file using the same chunk size ```text 4970 19:28:42.851418442 0 rocket-worker-t (11532) > read fd=16(<f>/srv/conduit/.local/share/conduit/conduit.db) size=2048 4971 19:28:42.851431543 0 rocket-worker-t (11532) > lseek fd=16(<f>/srv/conduit/.local/share/conduit/conduit.db) offset=0 whence=0(SEEK_SET) 4973 19:28:42.851433243 0 rocket-worker-t (11532) > read fd=16(<f>/srv/conduit/.local/share/conduit/conduit.db) size=2048 4974 19:28:42.851442544 0 rocket-worker-t (11532) > fcntl fd=11(<f>/srv/conduit/.local/share/conduit/conduit.db-shm) cmd=8(F_SETLK) 4980 19:28:42.851517149 0 rocket-worker-t (11532) > read fd=14(<f>/srv/conduit/.local/share/conduit/conduit.db) size=2048 4981 19:28:42.851522949 0 rocket-worker-t (11532) > lseek fd=14(<f>/srv/conduit/.local/share/conduit/conduit.db) offset=0 whence=0(SEEK_SET) 4983 19:28:42.851524749 0 rocket-worker-t (11532) > read fd=14(<f>/srv/conduit/.local/share/conduit/conduit.db) size=2048 4984 19:28:42.851529449 0 rocket-worker-t (11532) > lseek fd=14(<f>/srv/conduit/.local/share/conduit/conduit.db) offset=0 whence=0(SEEK_SET) 4986 19:28:42.851531049 0 rocket-worker-t (11532) > read fd=14(<f>/srv/conduit/.local/share/conduit/conduit.db) size=2048 4987 19:28:42.851536150 0 rocket-worker-t (11532) > lseek fd=14(<f>/srv/conduit/.local/share/conduit/conduit.db) offset=0 whence=0(SEEK_SET) 4989 19:28:42.851537750 0 rocket-worker-t (11532) > read fd=14(<f>/srv/conduit/.local/share/conduit/conduit.db) size=2048 4990 19:28:42.851544950 0 rocket-worker-t (11532) > lseek fd=14(<f>/srv/conduit/.local/share/conduit/conduit.db) offset=0 whence=0(SEEK_SET) 4992 19:28:42.851546650 0 rocket-worker-t (11532) > read fd=14(<f>/srv/conduit/.local/share/conduit/conduit.db) size=2048 4993 19:28:42.851550351 0 rocket-worker-t (11532) > lseek fd=14(<f>/srv/conduit/.local/share/conduit/conduit.db) offset=0 whence=0(SEEK_SET) 4995 19:28:42.851551951 0 rocket-worker-t (11532) > read fd=14(<f>/srv/conduit/.local/share/conduit/conduit.db) size=2048 4996 19:28:42.851556751 0 rocket-worker-t (11532) > lseek fd=14(<f>/srv/conduit/.local/share/conduit/conduit.db) offset=0 whence=0(SEEK_SET) 4998 19:28:42.851558251 0 rocket-worker-t (11532) > read fd=14(<f>/srv/conduit/.local/share/conduit/conduit.db) size=2048 4999 19:28:42.851570452 0 rocket-worker-t (11532) > fcntl fd=11(<f>/srv/conduit/.local/share/conduit/conduit.db-shm) cmd=8(F_SETLK) 6003 19:28:43.432241388 0 rocket-worker-t (11532) > read fd=16(<f>/srv/conduit/.local/share/conduit/conduit.db) size=2048 6004 19:28:43.432254588 0 rocket-worker-t (11532) > lseek fd=16(<f>/srv/conduit/.local/share/conduit/conduit.db) offset=0 whence=0(SEEK_SET) 6006 19:28:43.432256289 0 rocket-worker-t (11532) > read fd=16(<f>/srv/conduit/.local/share/conduit/conduit.db) size=2048 6007 19:28:43.432265289 0 rocket-worker-t (11532) > fcntl fd=11(<f>/srv/conduit/.local/share/conduit/conduit.db-shm) cmd=8(F_SETLK) 6013 19:28:43.432338494 0 rocket-worker-t (11532) > read fd=14(<f>/srv/conduit/.local/share/conduit/conduit.db) size=2048 6014 19:28:43.432344494 0 rocket-worker-t (11532) > lseek fd=14(<f>/srv/conduit/.local/share/conduit/conduit.db) offset=0 whence=0(SEEK_SET) 6016 19:28:43.432346194 0 rocket-worker-t (11532) > read fd=14(<f>/srv/conduit/.local/share/conduit/conduit.db) size=2048 6017 19:28:43.432351495 0 rocket-worker-t (11532) > lseek fd=14(<f>/srv/conduit/.local/share/conduit/conduit.db) offset=0 whence=0(SEEK_SET) 6019 19:28:43.432353195 0 rocket-worker-t (11532) > read fd=14(<f>/srv/conduit/.local/share/conduit/conduit.db) size=2048 6020 19:28:43.432358195 0 rocket-worker-t (11532) > lseek fd=14(<f>/srv/conduit/.local/share/conduit/conduit.db) offset=0 whence=0(SEEK_SET) 6022 19:28:43.432359795 0 rocket-worker-t (11532) > read fd=14(<f>/srv/conduit/.local/share/conduit/conduit.db) size=2048 6023 19:28:43.432367596 0 rocket-worker-t (11532) > lseek fd=14(<f>/srv/conduit/.local/share/conduit/conduit.db) offset=0 whence=0(SEEK_SET) 6025 19:28:43.432369196 0 rocket-worker-t (11532) > read fd=14(<f>/srv/conduit/.local/share/conduit/conduit.db) size=2048 6026 19:28:43.432373096 0 rocket-worker-t (11532) > lseek fd=14(<f>/srv/conduit/.local/share/conduit/conduit.db) offset=0 whence=0(SEEK_SET) 6028 19:28:43.432374596 0 rocket-worker-t (11532) > read fd=14(<f>/srv/conduit/.local/share/conduit/conduit.db) size=2048 6029 19:28:43.432379096 0 rocket-worker-t (11532) > lseek fd=14(<f>/srv/conduit/.local/share/conduit/conduit.db) offset=0 whence=0(SEEK_SET) 6031 19:28:43.432380696 0 rocket-worker-t (11532) > read fd=14(<f>/srv/conduit/.local/share/conduit/conduit.db) size=2048 ``` That's for the read syscalls... many syscalls seeking to 0 and reading like in a loop... Thats why disk read input is like crazy And finally a pattern that makes no sense to me either... ```text 202965 19:53:26.866046815 0 rocket-worker-t (11532) > fstat fd=9(<f>/srv/conduit/.local/share/conduit/conduit.db) 202969 19:53:26.866063216 0 rocket-worker-t (11532) > read fd=10(<f>/srv/conduit/.local/share/conduit/conduit.db-wal) size=2048 202970 19:53:26.866071717 0 rocket-worker-t (11532) > lseek fd=9(<f>/srv/conduit/.local/share/conduit/conduit.db) offset=0 whence=0(SEEK_SET) 202972 19:53:26.866073117 0 rocket-worker-t (11532) > write fd=9(<f>/srv/conduit/.local/share/conduit/conduit.db) size=2048 202975 19:53:26.866094318 0 rocket-worker-t (11532) > read fd=10(<f>/srv/conduit/.local/share/conduit/conduit.db-wal) size=2048 202976 19:53:26.866096218 0 rocket-worker-t (11532) > lseek fd=9(<f>/srv/conduit/.local/share/conduit/conduit.db) offset=0 whence=0(SEEK_SET) 202978 19:53:26.866097318 0 rocket-worker-t (11532) > write fd=9(<f>/srv/conduit/.local/share/conduit/conduit.db) size=2048 202981 19:53:26.866101619 0 rocket-worker-t (11532) > read fd=10(<f>/srv/conduit/.local/share/conduit/conduit.db-wal) size=2048 202982 19:53:26.866103719 0 rocket-worker-t (11532) > lseek fd=9(<f>/srv/conduit/.local/share/conduit/conduit.db) offset=0 whence=0(SEEK_SET) 202984 19:53:26.866104719 0 rocket-worker-t (11532) > write fd=9(<f>/srv/conduit/.local/share/conduit/conduit.db) size=2048 202987 19:53:26.866108719 0 rocket-worker-t (11532) > read fd=10(<f>/srv/conduit/.local/share/conduit/conduit.db-wal) size=2048 202988 19:53:26.866110919 0 rocket-worker-t (11532) > lseek fd=9(<f>/srv/conduit/.local/share/conduit/conduit.db) offset=0 whence=0(SEEK_SET) 202990 19:53:26.866111919 0 rocket-worker-t (11532) > write fd=9(<f>/srv/conduit/.local/share/conduit/conduit.db) size=2048 202993 19:53:26.866115319 0 rocket-worker-t (11532) > read fd=10(<f>/srv/conduit/.local/share/conduit/conduit.db-wal) size=2048 202994 19:53:26.866117420 0 rocket-worker-t (11532) > lseek fd=9(<f>/srv/conduit/.local/share/conduit/conduit.db) offset=0 whence=0(SEEK_SET) 202996 19:53:26.866118420 0 rocket-worker-t (11532) > write fd=9(<f>/srv/conduit/.local/share/conduit/conduit.db) size=2048 202999 19:53:26.866122720 0 rocket-worker-t (11532) > read fd=10(<f>/srv/conduit/.local/share/conduit/conduit.db-wal) size=2048 203000 19:53:26.866125320 0 rocket-worker-t (11532) > lseek fd=9(<f>/srv/conduit/.local/share/conduit/conduit.db) offset=0 whence=0(SEEK_SET) 203002 19:53:26.866126320 0 rocket-worker-t (11532) > write fd=9(<f>/srv/conduit/.local/share/conduit/conduit.db) size=2048 203005 19:53:26.866129620 0 rocket-worker-t (11532) > read fd=10(<f>/srv/conduit/.local/share/conduit/conduit.db-wal) size=2048 203006 19:53:26.866131521 0 rocket-worker-t (11532) > lseek fd=9(<f>/srv/conduit/.local/share/conduit/conduit.db) offset=0 whence=0(SEEK_SET) 203008 19:53:26.866132521 0 rocket-worker-t (11532) > write fd=9(<f>/srv/conduit/.local/share/conduit/conduit.db) size=2048 ``` fd=10 reads 2K chunks from the WAL file but fd=9 seeks to the beginning of the database file, writes a 2K block of data then fd=10 reads the next chunk and fd=9 overwrites the first block? Or do I st. misunderstand here how lseek() works (https://man7.org/linux/man-pages/man2/lseek.2.html)