Error writting metadata to file. dir_metadata has wrong size

Server
1

Hello

This issue has been probably treated in another post, however I’ve been unable to find a good solution to it

Some of our PCs is recurrently having the following issue. All incremental file backups fail with this error when trying to backup a folder in C (always the same folder):

13/02/17 11:46  	WARNING  	Restarting shadow copy of C:\ because it was started by this server
13/02/17 11:46  	INFO  	Scanning for changed hard links on volume of "C"...
13/02/17 11:46  	INFO  	Indexing of "C" done. 98 filesystem lookups 10285 db lookups and 83 db updates
13/02/17 11:46  	WARNING  	Restarting shadow copy of D:\ because it was started by this server
13/02/17 11:46  	INFO  	Scanning for changed hard links on volume of "D"...
13/02/17 11:46  	INFO  	Indexing of "D" done. 1 filesystem lookups 195 db lookups and 1 db updates
13/02/17 11:46  	DEBUG  	PC1: Doing backup with hashed transfer...
13/02/17 11:46  	INFO  	PC1: Loading file list...
13/02/17 11:47  	DEBUG  	PC1 Starting incremental backup...
13/02/17 11:47  	INFO  	PC1: Calculating file tree differences...
13/02/17 11:47  	INFO  	PC1: Creating snapshot...
13/02/17 11:47  	INFO  	PC1: Deleting files in snapshot... (0)
13/02/17 11:47  	INFO  	PC1: Deleting files in hash snapshot...
13/02/17 11:47  	INFO  	PC1: Indexing file entries from last backup...
13/02/17 11:47  	INFO  	PC1: Linking unchanged and loading new files...
13/02/17 11:47  	WARNING  	Directory "/var/local/backup/urbackup/PC1/170213-1146/C/Migracion/Users/" does already exist.
13/02/17 11:47  	WARNING  	Directory "/var/local/backup/urbackup/PC1/170213-1146/.hashes/C/Migracion/Users/" does already exist. - File exists (errorcode=17)
13/02/17 11:47  	ERROR  	Writing directory metadata to "/var/local/backup/urbackup/PC1/170213-1146/.hashes/C/Migracion/Users//.dir_metadata" failed.
13/02/17 11:47  	INFO  	Waiting for file transfers...
13/02/17 11:47  	INFO  	Waiting for file hashing and copying threads...
13/02/17 11:47  	INFO  	Saving file metadata...
13/02/17 11:47  	INFO  	Writing new file list...
13/02/17 11:47  	DEBUG  	Some metadata was missing
13/02/17 11:47  	INFO  	Number of copyied file entries from last backup is 7919
13/02/17 11:47  	ERROR  	Fatal error during backup. Backup not completed
13/02/17 11:47  	INFO  	Transferred 14.1219 MB - Average speed: 9.94986 MBit/s
13/02/17 11:47  	DEBUG  	Script does not exist urbackup/post_incr_filebackup
13/02/17 11:47  	INFO  	Time taken for backing up client PC1: 46s
13/02/17 11:47  	ERROR  	Backup failed

Additionally I can see these errors in /var/local/urbackup.log:

2017-02-13 11:46:57: WARNING: Restarting shadow copy of D:\ because it was started by this server
2017-02-13 11:47:09: WARNING: Directory "/var/local/backup/urbackup/PC1/170213-1146/C/Migracion/Users/" does already exist.
2017-02-13 11:47:09: WARNING: Directory  "/var/local/backup/urbackup/PC1/170213-1146/.hashes/C/Migracion/Users/" does already exist. - File exists (errorcode=17)
2017-02-13 11:47:09: WARNING: File "/var/local/backup/urbackup/PC1/170213-1146/.hashes/C/Migracion/Users//.dir_metadata" has wrong size. Should=8 is=51. Error writing metadata to file. -1
2017-02-13 11:47:09: ERROR: Writing directory metadata to "/var/local/backup/urbackup/PC1/170213-1146/.hashes/C/Migracion/Users//.dir_metadata" failed.
2017-02-13 11:47:21: ERROR: Fatal error during backup. Backup not completed
2017-02-13 11:47:21: ERROR: Backup failed

The server is ubuntu 16.04; the filesystem for backups is btrfs.

So far I’ve tried to delete /var/local/backup/urbackup/PC1/170213-1146/.hashes/C/Migracion/Users//.dir_metadata but with no change on the problem.

Thanks in advance

2
  1. What is your UrBackup server version.
  2. Does running the remove_unknown script help?
3

Hi ttrammell, thanks for your response,

UrBackup Server v2.0.38.1660 from package 2.0.38.1660-1ubuntu1~xenial

No as far as it does some stuff and then it seems to hang at:
[…]
2017-02-14 18:28:25: Active query(0): PRAGMA journal_mode = DELETE
2017-02-14 18:28:25: SQLITE_BUSY in CQuery::Execute Stmt: [PRAGMA journal_mode = DELETE]
2017-02-14 18:28:25: Active query(0): PRAGMA journal_mode = DELETE
2017-02-14 18:28:25: SQLITE_BUSY in CQuery::Execute Stmt: [PRAGMA journal_mode = DELETE]
2017-02-14 18:28:25: Active query(0): PRAGMA journal_mode = DELETE
2017-02-14 18:28:25: ERROR: SQLITE: Long running query Stmt: [PRAGMA journal_mode = DELETE]
2017-02-14 18:28:25: ERROR: Active query(0): PRAGMA journal_mode = DELETE

should I stop urbackupsrv main process in order to run remove_unknown?

4

Any hints on this issue?

5

Mmm…

I’m not one-hundred percent sure about the SQLite errors.

What does the cleanup script show, and could you try restarting the service on the client - maybe even try re-association by removing the server_idents.txt file from the client?

6

I’m going to close this issue

I’ve finally wiped-out all the files on this backup and start again with this client.

Thank you