Urbackup 1.4.10 windows client problem (NTFS journal related?)


#1

Hi!

I’ve started using URbackup in order to back up windows clients. Windows client 1.4.10 (and 1.4.9), server on debian 1.4.11.

I’ve got two test machines: one windows 2012 server the one windows 7. Those back up both images of “C:” and files backups properly. Both full and incremental.

I’ve got one machine: windows 2008 R2 server that worked properly for a week and then stopped backuping. URbackup says “There was an error. Currently nothing can be backed up”. I’ve reinstalled it a few times, to exclude issues with the internal database (i deleted everything urbackup related) but during first backup image or file, it returned to this state after 20-30 minutes of indexing data.

Current NTFS maximum journal size is 0x2000000.

What’s in debug log of the client:

This is what happened, after a fresh client was installed, and a incremental file backup started:

2015-12-08 22:58:50: WARNING: Upgrading…
2015-12-08 22:58:50: ERROR: Error preparing Query [SELECT tvalue FROM misc WHERE tkey=‘db_version’]: no such table: misc
2015-12-08 22:58:51: ERROR: Error preparing Query [DROP INDEX filehashes_idx]: no such index: filehashes_idx
2015-12-08 22:59:38: WARNING: Info not found at ‘c:’ - reindexing
2015-12-08 23:00:53: ERROR: Error for Volume ‘c:’: Journal entry deleted (StartUsn=376590403456)
2015-12-08 23:00:53: ERROR: Reindexing Volume 'c:'
2015-12-08 23:00:53: ERROR: DeviceInfo: FirstUsn=376591351808 NextUsn=376625221712 MaximumSize=33554432 AllocationDelta=4194304
2015-12-08 23:00:54: WARNING: Stopped indexing process
2015-12-08 23:00:54: WARNING: Parent of file with FRN 15199648742465428 (Name “update.ver”) with FRN 25051272927338411 not found.
Searching via MFT as fallback.
2015-12-08 23:00:54: WARNING: Couldn’t follow up to root via Database. Falling back to MFT. Current path: mirror
2015-12-08 23:00:54: WARNING: Couldn’t follow up to root via Database. Falling back to MFT. Current path: Server\mirror\

somewhere along the way there is an error:

2015-12-08 23:03:23: WARNING: Couldn’t follow up to root via Database. Falling back to MFT. Current path: UrBackupClient
2015-12-08 23:03:23: WARNING: Couldn’t follow up to root via Database. Falling back to MFT. Current path: Roaming\UrBackupClient
2015-12-08 23:03:47: ERROR: Error for Volume ‘c:’: Journal entry deleted (StartUsn=376792152336)
2015-12-08 23:03:47: ERROR: Reindexing Volume 'c:'
2015-12-08 23:03:47: ERROR: DeviceInfo: FirstUsn=376792678400 NextUsn=376828623040 MaximumSize=33554432 AllocationDelta=4194304
2015-12-08 23:03:47: WARNING: Stopped indexing process
2015-12-08 23:03:47: WARNING: Parent of file with FRN 26458647811104968 (Name “open_files.dat”) with FRN 22236523160457825 not fou
nd. Searching via MFT as fallback.
2015-12-08 23:03:47: WARNING: Couldn’t follow up to root via Database. Falling back to MFT. Current path: urbackup
2015-12-08 23:03:47: WARNING: Couldn’t follow up to root via Database. Falling back to MFT. Current path: UrBackup\urbackup
2015-12-08 23:03:47: WARNING: Parent of file with FRN 15199648742465428 (Name “update.ver”) with FRN 25051272927338411 not found.
Searching via MFT as fallback.
2015-12-08 23:03:47: WARNING: Couldn’t follow up to root via Database. Falling back to MFT. Current path: mirror
2015-12-08 23:03:47: WARNING: Couldn’t follow up to root via Database. Falling back to MFT. Current path: Server\mirror
2015-12-08 23:03:47: WARNING: Couldn’t follow up to root via Database. Falling back to MFT. Current path: ESET Remote Administrato
r\Server\mirror
2015-12-08 23:03:47: WARNING: Couldn’t follow up to root via Database. Falling back to MFT. Current path: ESET\ESET Remote Adminis
trator\Server\mirror
2015-12-08 23:03:47: WARNING: Parent of file with FRN 17451448556132132 (Name “etilqs_YvdPp5UU3rNrizS”) with FRN 281474976713628 n
ot found. Searching via MFT as fallback.
2015-12-08 23:03:47: WARNING: Couldn’t follow up to root via Database. Falling back to MFT. Current path: Temp
2015-12-08 23:03:48: WARNING: Indexing was not finished at ‘c:’ - reindexing

At this moment urbackup starts saying that there was an error and nothing can be backed up. And debug log is filled with information just like this:

2015-12-08 23:04:58: ERROR: Error for Volume ‘c:’: Journal entry deleted (StartUsn=376879130016)
2015-12-08 23:04:58: ERROR: Reindexing Volume 'c:'
2015-12-08 23:04:58: ERROR: DeviceInfo: FirstUsn=376880758784 NextUsn=376915496384 MaximumSize=33554432 AllocationDelta=4194304
2015-12-08 23:06:03: ERROR: Error for Volume ‘c:’: Journal entry deleted (StartUsn=376962551232)
2015-12-08 23:06:03: ERROR: Reindexing Volume 'c:'
2015-12-08 23:06:03: ERROR: DeviceInfo: FirstUsn=376964644864 NextUsn=376999334048 MaximumSize=33554432 AllocationDelta=4194304

I’m basicaly a linux admin and try to kill windows with fire. But this is something that I cannot avoid. What are your suggestions? What is wrong here? Everything else works OK on this particular VM apart from the UrBackup client. This machine is a MSSQL server, about 280 GB data to be backed up, on top of XEN with GPLPV drivers.


#2

Could you put it into debug log mode (as described here) and upload/send a full log file?


#3

What I have done:

  • uninstalled urbackup client
  • installed again
  • stopped immediatelly and added debug configuration
  • started
  • changed client name to have a fresh start on the server
  • full image and file backups went OK during the night (strange).

I will wait for this problem to happen again. It did previously after ~30 mins