MDB_KEYEXIST: Key/data pair already exists

I am running UrBackup Server v2.4.15.0 inside a Freebsd 13.0 Jail.

I haven’t actively looked at it in a while and just noticed it didn’t start after a reboot. So i am not sure since when this issue exists or how it came to be.

But when i start UrBackup it starts indexing the files and stops with the following Error message:

2022-05-19 19:52:25: Starting HTTP-Server on port 55414
2022-05-19 19:52:25: HTTP: Server started up successfully!
2022-05-19 19:52:25: SQLite: recovered 4452 frames from WAL file /var/urbackup/backup_server.db-wal code: 283
2022-05-19 19:52:25: SQLite: recovered 7431 frames from WAL file /var/urbackup/backup_server_link_journal.db-wal code: 283
2022-05-19 19:52:26: SQLite: recovered 109713 frames from WAL file /var/urbackup/backup_server_links.db-wal code: 283
2022-05-19 19:52:26: SQLite: recovered 74 frames from WAL file /var/urbackup/backup_server_settings.db-wal code: 283
2022-05-19 19:52:26: SQLite: recovered 4452 frames from WAL file /var/urbackup/backup_server.db-wal code: 283
2022-05-19 19:52:26: SQLite: recovered 74 frames from WAL file /var/urbackup/backup_server_settings.db-wal code: 283
2022-05-19 19:52:26: SQLite: recovered 109713 frames from WAL file /var/urbackup/backup_server_links.db-wal code: 283
2022-05-19 19:52:26: SQLite: recovered 7431 frames from WAL file /var/urbackup/backup_server_link_journal.db-wal code: 283
2022-05-19 19:52:26: Deleting database journal...
2022-05-19 19:52:26: Copying/reflinking database...
2022-05-19 19:52:26: Reflink ioctl failed. errno=14
2022-05-19 19:52:26: Reflinking failed. Falling back to copying...
2022-05-19 19:52:30: WARNING: Creating file entry index. This might take a while...
2022-05-19 19:52:30: Getting number of files...
2022-05-19 19:52:30: Dropping index...
2022-05-19 19:52:30: Starting creating files index...
2022-05-19 19:52:30: Creating files index: 0% finished
2022-05-19 19:52:34: Creating files index: 0.1% finished
2022-05-19 19:52:34: File entry index contains 1000 entries now.
2022-05-19 19:52:34: Creating files index: 0.2% finished
2022-05-19 19:52:34: Creating files index: 0.3% finished
2022-05-19 19:52:34: File entry index contains 2000 entries now.
2022-05-19 19:52:34: Creating files index: 0.4% finished
2022-05-19 19:52:34: File entry index contains 3000 entries now.
2022-05-19 19:52:34: Creating files index: 0.5% finished
2022-05-19 19:52:35: Creating files index: 0.6% finished
2022-05-19 19:52:35: File entry index contains 4000 entries now.
2022-05-19 19:52:35: Creating files index: 0.7% finished
2022-05-19 19:52:35: File entry index contains 5000 entries now.
2022-05-19 19:52:35: Creating files index: 0.8% finished
2022-05-19 19:52:36: Creating files index: 0.9% finished

=========== Cut because all messages are similar

2022-05-19 19:52:45: Creating files index: 15.1% finished
2022-05-19 19:52:45: File entry index contains 104000 entries now.
2022-05-19 19:52:45: Creating files index: 15.2% finished
2022-05-19 19:52:45: File entry index contains 105000 entries now.
2022-05-19 19:52:45: Creating files index: 15.3% finished
2022-05-19 19:52:45: Creating files index: 15.4% finished
2022-05-19 19:52:45: File entry index contains 106000 entries now.
2022-05-19 19:52:45: ERROR: LMDB: Failed to put data (MDB_KEYEXIST: Key/data pair already exists)
2022-05-19 19:52:45: ERROR: LMDB error after putting element. Error state interrupting..
2022-05-19 19:52:45: ERROR: Setting up file index failed
2022-05-19 19:52:45: ERROR: Could not create or open file entry index. Exiting.

Does anyone know what causes this issue or how i can solve it? (or at least how i can see which Key/data pair already exists?)

All the best,

Nicoals

Ideas:

Maybe apply this patch Skip small files and files without hash in index rebuild · uroni/urbackup_backend@8c24d2d · GitHub and see if that helps

Edit the log message in LMDBFileIndex.cpp to output information about the problematic file entry

Run an integrity check on backup_server_files.db:

sqlite3 backup_server_files.db

PRAMGA integrity_check;

The file index doesn’t get deleted on its own… maybe look into what caused it to be deleted?

Thanks for the swift reply.

Since this is only my secondary backup i had to think a bit about this setup and i remembered that i had automatic snapshots for the backup directory enabled (but not the jail itself)

And it seems like urbackup also saves its database files there (in addition to /var/urbackup). So i restored a week old snapshot from the data dir, copied the database files over to /var/urbackup and started the service and now it seems to work.

Since i don’t have any snapshots of the jail i sadly can’t reproduce what caused this error.

But thank you so much for the reply and the 2 quite helpful suggestions (While it wasn’t a corrupted Database, the comment with the databases got me to look into the backup dir.)