Incremental backups appearing to work but not really

general discussion
1

Firstly, have to say amazing software, couldn’t believe it picked up that I had moved a file. It did the same move on the backup without using up extra disk space - brilliant.

I’ve hit trouble though where the incremental backups have stopped working (and only worked for a day or so). There are entries in ‘last activities’ as expected, but the Used Storage is suspiciously low. When I checked I realised the incremental backup wasn’t working, as the backup was out of date. Also the ‘Last Seen’ field is out of date with respect to the ‘Last Backup’ field on the Status tab. The Last Seen matches when the last incremental backup worked.

My Setup:
I have the server running on Win7x64 and a Win7x64 client on the local LAN. What I’m having trouble with is a Internet client which is running on Windows 2008 Web Server R2.

Errors I’m Seeing (in debug.log):
On Lan client: WARNING: FileSrv: Error: Setting TCP_NODELAY=TRUE failed. Unable to create shadowcopy, which is expected as I’m using TrueCrypt.
The error I’m getting on the Internet client is: ERROR: Internet server auth failed. Error: Token not found

I wondered what could be causing this, as it was previously working and just stopped without any apparent changes made to config?

Thanks in advance for any help. Would be wonderful to get it working again.

Mark

2

Bit more information:

Managed to get LAN client working again by reinstalling and rebooting. However, that didn’t work on the internet client.

Only Warnings on server are reported, which are
HT: Error creating hardlink or
Creating hardlink… failed.

In debug.log on client getting:
2013-02-15 13:43:48: ERROR: Couldn’t follow up to root. Current path: $RmMetadata$TxfLog\
(in addition to hard link errors)

Thank you for your time,

Mark

3

Are you still getting the

errors?

If yes, what is your server and client version? The client may have auto-updated a few days ago. That could be the reason it stopped working. (That should not happen, of course)

The Server should have similar error messages if a client fails to authenticate:

Authentication failed in InternetServiceConnector::ReceivePackets: Token not found

for example.

The supply of tokens at the client should be exhausted at some point. Then there should be a different error message in the log files.

4

Thank you for the reply.

Client and server all version 63.

Can confirm that the Windows LAN client has stopped working again. The symptoms are that in Activities it goes from 0% complete to 100% completed very quickly but then the disk churns for quite a while (with it showing 100% progress) before an entry appears in Last activities with the very low Used Storage. All windows client task bar icons are coloured white with 'Last backup on ’ reporting expected date.

Errors reported in Logs for Windows LAN client:

Just problem activating shadow copy and a couple of FILE_DOESNT_EXIST on temporary files in a MySQL data directory. Warnings are a few creating hardlink.

Errors reported in Logs for Internet LAN client:

Very similar, i.e. occasional FILE_DOESNT_EXIST (as expected) and hardlink warnings.

Errors reported in debug.log for Windows LAN client:

2013-02-17 01:09:10: ERROR: backupcom->AddToSnapshotSet(volume_path, GUID_NULL, &dir->ref->ssetid) failed: EC=VSS_E_UNEXPECTED_PROVIDER_ERROR
2013-02-17 01:09:11: ERROR: Creating shadowcopy of “Z” failed in indexDirs().
2013-02-17 01:09:15: ERROR: backupcom->AddToSnapshotSet(volume_path, GUID_NULL, &dir->ref->ssetid) failed: EC=VSS_E_UNEXPECTED_PROVIDER_ERROR
2013-02-17 01:09:15: ERROR: Creating shadowcopy of “Home” failed in indexDirs().
2013-02-17 01:09:18: WARNING: FileSrv: Error: Setting TCP_NODELAY=TRUE failed
2013-02-17 01:09:27: ERROR: backupcom->AddToSnapshotSet(volume_path, GUID_NULL, &dir->ref->ssetid) failed: EC=VSS_E_UNEXPECTED_PROVIDER_ERROR
2013-02-17 01:09:27: ERROR: Creating shadowcopy of “Z” failed.
2013-02-17 01:23:24: ERROR: backupcom->AddToSnapshotSet(volume_path, GUID_NULL, &dir->ref->ssetid) failed: EC=VSS_E_UNEXPECTED_PROVIDER_ERROR
2013-02-17 01:23:24: ERROR: Creating shadowcopy of “Home” failed.
2013-02-17 05:13:42: ERROR: backupcom->AddToSnapshotSet(volume_path, GUID_NULL, &dir->ref->ssetid) failed: EC=VSS_E_UNEXPECTED_PROVIDER_ERROR
2013-02-17 05:13:42: ERROR: Creating shadowcopy of “Z” failed in indexDirs().
2013-02-17 05:13:47: ERROR: backupcom->AddToSnapshotSet(volume_path, GUID_NULL, &dir->ref->ssetid) failed: EC=VSS_E_UNEXPECTED_PROVIDER_ERROR
2013-02-17 05:13:47: ERROR: Creating shadowcopy of “Home” failed in indexDirs().
2013-02-17 05:13:51: WARNING: FileSrv: Error: Setting TCP_NODELAY=TRUE failed
2013-02-17 05:13:59: ERROR: backupcom->AddToSnapshotSet(volume_path, GUID_NULL, &dir->ref->ssetid) failed: EC=VSS_E_UNEXPECTED_PROVIDER_ERROR
2013-02-17 05:13:59: ERROR: Creating shadowcopy of “Z” failed.
2013-02-17 05:27:47: ERROR: backupcom->AddToSnapshotSet(volume_path, GUID_NULL, &dir->ref->ssetid) failed: EC=VSS_E_UNEXPECTED_PROVIDER_ERROR
2013-02-17 05:27:47: ERROR: Creating shadowcopy of “Home” failed.
2013-02-17 09:18:14: ERROR: backupcom->AddToSnapshotSet(volume_path, GUID_NULL, &dir->ref->ssetid) failed: EC=VSS_E_UNEXPECTED_PROVIDER_ERROR
2013-02-17 09:18:15: ERROR: Creating shadowcopy of “Z” failed in indexDirs().
2013-02-17 09:18:19: ERROR: backupcom->AddToSnapshotSet(volume_path, GUID_NULL, &dir->ref->ssetid) failed: EC=VSS_E_UNEXPECTED_PROVIDER_ERROR
2013-02-17 09:18:19: ERROR: Creating shadowcopy of “Home” failed in indexDirs().
2013-02-17 09:18:22: WARNING: FileSrv: Error: Setting TCP_NODELAY=TRUE failed
2013-02-17 09:18:31: ERROR: backupcom->AddToSnapshotSet(volume_path, GUID_NULL, &dir->ref->ssetid) failed: EC=VSS_E_UNEXPECTED_PROVIDER_ERROR
2013-02-17 09:18:31: ERROR: Creating shadowcopy of “Z” failed.
2013-02-17 09:32:22: ERROR: backupcom->AddToSnapshotSet(volume_path, GUID_NULL, &dir->ref->ssetid) failed: EC=VSS_E_UNEXPECTED_PROVIDER_ERROR
2013-02-17 09:32:22: ERROR: Creating shadowcopy of “Home” failed.

Errors reported in debug.log for Windows Internet client:

2013-02-16 23:54:53: ERROR: Internet server auth failed. Error: Token not found
2013-02-17 11:57:34: ERROR: Internet server auth failed. Error: Token not found

Errors reported in urbackup.log on server:

Just lots of hardlink files.

Note, I have got a couple of directories with a huge number of little files in the them, i.e. 22,000 in one and 40,000 in the other.

I may try a reinstallation as it is quite a fundamental problem I’m having. I may wait a bit though so not as to upset my ISP, as the data I need to transfer is ~60Gb on first run.

Huge thanks for the help,

Mark

5

Hello,

Amazing Backup Solution i must tell !!!

I’m experiencing a problem on incremental backup on certain workstations :

many times, it s like there are no new files but “au contraire”

i’ve tried many things, and i noticed that incremental backup works only one time when i just uninstall and reinstall the client .
Then it give me agin an incremental session with 0 bytes in 1 minutes for all newt sessions

for other workstations under XP or vista, no problem at all …

How is it possible to solve or to prevent this problem ??

Regards

6

One last analysis :

the problem seems to come from the client : filelist.ub is not up to date, that ’ why incremental backup syncs nothing

it s been updated only when i uninstall and install again

I use the 1.1 version of the server and client

…

7

If you two are doing file backups of whole volumes (e.g. Z:\ ?) then I may have found and fixed the bug. New version is here:
https://sourceforge.net/projects/urbackup/files/Client/1.1.1/

8

Thanks

I ve just tried the last 1.1.1 version and the problem is still happening

no filelist.ub update except when i reinstall the client

i do the c:\documents and settings backup, and not the whole drive

9

[quote=“mehdincd”]Thanks

I ve just tried the last 1.1.1 version and the problem is still happening

no filelist.ub update except when i reinstall the client

i do the c:\documents and settings backup, and not the whole drive[/quote]

Could you send me the client logfile (to martin@urbackup.org )? It’s debug.log in C:\Program files\UrBackup\ . Preferably one where UrBackup is in debug log mode – change warn to debug in args.txt and restart the UrBackupBackend service.

10

Just installed new build. LAN client successfully did incremental back up. I then manually kicked off another and it successfully picked up a file change. Just trying the internet client now (will be slower).

I am indeed doing full volume backups (they are data disks - OS on separate drive) with a few directories marked as exceptions, e.g. temp and download.

Huge thanks,

Mark

11

Hi Martin,

some more information :

on my network, all xp clients are behaving well except for 3 :
they have the same hardware and software history

at incremental session start, the windows application logs shows the follwing messages :

for 2 Dell optiplex PC under xp :
SOURCE : MSDTC
ID EVENT 2444

for 1 Dell optiplex PC under xp :
SOURCE : Ci
EVENT 4137

Maybe this will help … may be it s coming from the indexing service on XP, on certain machine ???

12

Hi Martin,

here is the debug sequence from the debug.log file with debug level set : despite new or updated files, filelist.ub won’t be updated

Shadowcopy path: \?\GLOBALROOT\Device\HarddiskVolumeShadowCopy1
2013-02-18 14:25:02: done.
2013-02-18 14:25:02: rc=0 hasError=true state=0
2013-02-18 14:25:03: Indexing “documents and settings”…
2013-02-18 14:25:05: Indexing of “documents and settings” done. 1 filesystem lookups 2577 db lookups and 0 db updates
2013-02-18 14:25:05: Deleting backup of changed dirs…
2013-02-18 14:25:06: rc=0 hasError=true state=0
2013-02-18 14:25:06: FileSrv: New Connection incomming
2013-02-18 14:25:06: WARNING: FileSrv: Error: Setting TCP_NODELAY=TRUE failed
2013-02-18 14:25:06: FileSrv: Info: Window size=524288
2013-02-18 14:25:06: FileSrv: Received data…
2013-02-18 14:25:06: FileSrv: Received a Packet.
2013-02-18 14:25:06: FileSrv: Sending file urbackup/filelist.ub
2013-02-18 14:25:06: FileSrv: Mapped name: C:\Program Files\UrBackup\urbackup\data\filelist.ub
2013-02-18 14:25:06: FileSrv: Reading last file part
2013-02-18 14:25:06: FileSrv: Info: File End
2013-02-18 14:25:06: FileSrv: Closed file.
2013-02-18 14:25:06: urbackupserver: New Connection incomming 103044609 s: 1068
2013-02-18 14:25:06: ClientService cmd: #I5WPCcBchx836R2IbJnd7#START SC “documents and settings”#token=vnOF87RNPeNvwpW0Rh1X
2013-02-18 14:25:06: orig_target=c:\documents and settings volpath=\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy1
2013-02-18 14:25:06: Shadowcopy already present.
2013-02-18 14:25:06: rc=0 hasError=true state=0
2013-02-18 14:25:10: urbackupserver: New Connection incomming 103047796 s: 728
2013-02-18 14:25:10: ClientService cmd: #I5WPCcBchx836R2IbJnd7#PING RUNNING -100-#token=vnOF87RNPeNvwpW0Rh1X
2013-02-18 14:25:10: rc=0 hasError=true state=0
2013-02-18 14:25:11: urbackupserver: New Connection incomming 103048859 s: 728
2013-02-18 14:25:11: urbackupserver: New Connection incomming 103048859 s: 904
2013-02-18 14:25:11: ClientService cmd: STATUS#pw=pYE3McWQoDhnkA20w0nGsRY8JNHVcC
2013-02-18 14:25:11: ClientService cmd: #I5WPCcBchx836R2IbJnd7#STOP SC “documents and settings”#token=vnOF87RNPeNvwpW0Rh1X
2013-02-18 14:25:11: rc=0 hasError=true state=0
2013-02-18 14:25:11: Deleting shadowcopy for path “\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy1\documents and settings” -2
2013-02-18 14:25:11: Deleting Shadowcopy for dir “c:”
2013-02-18 14:25:11: rc=0 hasError=true state=0
2013-02-18 14:25:11: urbackupserver: New Connection incomming 103048953 s: 904
2013-02-18 14:25:11: ClientService cmd: #I5WPCcBchx836R2IbJnd7#DID BACKUP
2013-02-18 14:25:11: rc=0 hasError=true state=0
2013-02-18 14:25:12: urbackupserver: New Connection incomming 103050125 s: 1052

On xp stations which fails incremental backup, i noticed those events in windows application log :

SOURCE : MSDTC
ID EVENT 2444

Source : Ci
EVENT 4137

13

Thanks for the logs. I think it’s because the “documents and settings” is all lower case while it is “Documents and Settings” in the file system. The OS-function I use to follow symlinks on Windows does change the case to the one on the filesystem on Windows 7 but not on Windows XP.

I’ve fixed the problem here:
https://sourceforge.net/projects/urbackup/files/Client/1.1.2RC/

The change is kind of intrusive. That’s why I want to test it for a while. You can try it as well, or change the case of the path.
Just FYI. It does follow the symlinks so it does suffice to only sepcify C:\documents and settings because Windows 7 has a Link C:\documents and settings -> C:\Users

14

All looking great now on both clients. Many, many thanks. Incredible support. It has made my week! :P

Cheers,

Mark

15

It looks to be ok now !!

i’v done two incrementals : both worked

I’m still testing … i’ll report you

I’ll set only incrementals so as to decrease the disk and netowrk load …

16

Ok incrementals are working well after the update 1.1.2-1

In the Activiies Page :
we have the required time displayed, but no Used Storage updates … maybe something is wrong here

17

It does not update that while other backups are running. So it might take a while.

18

Yes it s confirmed