Error with removing file in btrfs snapshot

[uroni]

Continuing the discussion from Help testing: UrBackup Server + Client 1.4:

@eli

Not sure if this is related to 1.4 or not but I’ll post it here.

I have a client that hasn’t backed up in a while, looks like because it was expecting a file on the backup server that wasn’t there?

Indexing of “Redirected Documents” done. 1 filesystem lookups 14562 db lookups and 0 db updates
Could not remove file “/mnt/backups//140803-1500/Share/Accounting/Quickbooks/**.QBW” in ::deleteFilesInSnapshot - No such file or directory (errorcode=2). It was already deleted.
Deleting files in snapshot failed (Server error)
Backup had errors. Deleting partial backup.
Exponential backoff: Waiting at least 21h 20m before next file backup

Can you find out with which version this error started occuring? Maybe I fixed it already.

To further narrow down what did not work I’d have to know when that
file was last downloaded, and what happend after that. For example a
client timeout or server shutdown. May be difficult to find out if you
don’t have debug logs.

You can get rid of this error for this client by running a full file backup.

[eli]

I’m pretty sure it was 1.4.1 beta 1 but not 100% sure on that.

I found the entry in urbackup.log on the server
014-07-09 00:36:22: ERROR: Could not remove file “/mnt/backups//140708-2340/Share/Accounting/Quickbooks/.QBW” in ::deleteFilesInSnapshot
2014-07-09 00:36:22: ERROR: Deleting files in snapshot failed (Server error)
2014-07-09 00:36:23: ERROR: Backup had errors. Deleting partial backup.

I think btrfs logs in the kernel log if remember correctly, looks like kernel.log doesn’t go back far enough unfortunately.

[eli]

So after a server reboot I’m getting this on other clients. I assume this is the same thing? This is with 1.4.1RC1 on the server. There’s no 140805-0236 directory on the server. I didn’t see anything useful regarding btrfs in the kernel logs.

04.08.14 23:40 Could not remove file “/mnt/backups/****/140805-0236/Exchange/priv1.edb” in ::deleteFilesInSnapshot - No such file or directory (errorcode=2). It was already deleted.
04.08.14 23:40 Deleting files in snapshot failed (Server error)
04.08.14 23:40 Backup had errors. Deleting partial backup.

[uroni]

Can you send me the complete logs of the last successfull file backup previous to the failed backups?

[uroni]

Thanks for the logs!

I think they gave me a hint. It may be fixed in the RC3 now (server side fix). If it still doesn’t work client/server debug logfiles would be nice.

FYI there may be other issues on that client that caused the assertions(crashes), because it probably deletes the shadow copy during the backup. This may be caused by not enough free space or a high write volume.

[eli]

Great, thank you.

I’ve updated the server and clients. I’ll let you know if I see more problems.

On the last client I kind of doubt there was a deleted snapshot since they’ve got quite a bit of disk space available but I wouldn’t completely rule it out.

[eli]

Still getting errors and urbackup on the server crashed again. These were the last lines in urbackup.log

2014-08-12 00:22:41: ERROR: Could not remove file “/mnt/backups//140811-2331/Share/Accounting/Quickbooks/*” in ::deleteFilesInSnapshot - No such file or directory (errorcode=2). It was already deleted.
2014-08-12 00:22:41: ERROR: Deleting files in snapshot failed (Server error)
2014-08-12 00:22:42: ERROR: Backup had errors. Deleting partial backup.

[uroni]

Updated it again. If it keeps crashing I’ll need more info (See https://urbackup.atlassian.net/wiki/display/US/Debugging+with+gdb+on+Linux ).

You need to run a full backup for the client with the deleteFilesInSnapshot problem, otherwise the problem won’t disappear.

[eli]

I’ve tried full file backups for the clients with issues too and they still have the problem. I’ll compile it with debugging enabled tonight. Thanks!