Client keeps fails full backup

tbaror · March 13, 2018, 7:30am

Hello,

I have a windows 2012 server client(client version 2.2.5) that backup for more than 6 months suddenly i get errors and backup fails on full backup never completes ,server version 2.2.8 .
error log shown below any idea what is wrong ?
Please advice thanks

=================client log===============

     Starting scheduled incremental image backup of volume "F:"...
Basing image backup on last full image backup
Error retrieving last image backup. Doing full image backup instead.
Received unknown block number: -1049215681440897362 (max: 91717120). Retrying...
Checksum for image block wrong. Retrying...
Checksum for image block wrong. Retrying...
Block sent out of sequence. Expected block >=183232 got 0. Retrying...
Checksum for image block wrong. Retrying...
Block sent out of sequence. Expected block >=788412 got 0. Retrying...
Checksum for image block wrong. Retrying...
Checksum for image block wrong. Retrying...
Error on client occurred: Error while reading from shadow copy device (1).  The system cannot find the file specified.
Time taken for backing up client SPORT-SQL.sport.local: 3h 48m 22s
Backup failed

=================server log============
Errors

03/13/18 08:46
	Error on client occurred: Error while reading from shadow copy device (1). The system cannot find the file specified.

02ebz06 · March 13, 2018, 2:13pm

You might try running CHKDSK on that F: drive to see it it has any problems.
Also try running REMOVE_UNKNOWN.BAT. in the urbackup directory to clean things up.
I think that is what it is called on Windows Servers.

tbaror · March 14, 2018, 12:56pm

Thanks for the answer
But couldn’t find any “REMOVE_UNKNOWN.BAT” , the only *.bat i fond is as follows
enable_debug_logging.bat
enable_internet_only.bat
prefilebackup.bat

any idea?
Thanks

uroni · March 14, 2018, 6:41pm

Can you have a look into the windows system/application event log?

02ebz06 · March 15, 2018, 3:31am

Manual says it is here on the Windows urbackup Server:
C:\Program Files\UrBackup\remove_unknown.bat

tbaror · March 16, 2018, 9:36am

OK I run the command

urbackupsrv remove-unknown

my server runs under jails on Freenas , when i run it i get following errors , any idea what about the SQLite errors?
Thanks

tkey=?]: unable to open database file. Retrying in 1s...                       
2018-03-16 02:32:16: WARNING: SQLite: cannot open file at line 34198 of [0ee482a
1e0] errorcode: 14                                                              
2018-03-16 02:32:16: WARNING: SQLite: os_unix.c:34198: (13) open(/usr/local/var/
urbackup/backup_server.db-shm) -  errorcode: 14                                 
2018-03-16 02:32:16: WARNING: SQLite: unable to open database file errorcode: 14
2018-03-16 02:32:16: ERROR: Error preparing Query [SELECT tvalue FROM misc WHERE
 tkey=?]: unable to open database file. Retrying in 1s...                       
2018-03-16 02:32:17: WARNING: SQLite: cannot open file at line 34198 of [0ee482a
1e0] errorcode: 14                                                              
2018-03-16 02:32:17: WARNING: SQLite: os_unix.c:34198: (13) open(/usr/local/var/
urbackup/backup_server.db-shm) -  errorcode: 14                                 
2018-03-16 02:32:17: WARNING: SQLite: unable to open database file errorcode: 14
2018-03-16 02:32:17: ERROR: Error preparing Query [SELECT tvalue FROM misc WHERE
 tkey=?]: unable to open database file. Retrying in 1s...                       
2018-03-16 02:32:18: WARNING: SQLite: cannot open file at line 34198 of [0ee482a
1e0] errorcode: 14                                                              
2018-03-16 02:32:18: WARNING: SQLite: os_unix.c:34198: (13) open(/usr/local/var/
urbackup/backup_server.db-shm) -  errorcode: 14                                 
2018-03-16 02:32:18: WARNING: SQLite: unable to open database file errorcode: 14
2018-03-16 02:32:18: ERROR: Error preparing Query [SELECT tvalue FROM misc WHERE
 tkey=?]: unable to open database file                                          
Segmentation fault

02ebz06 · March 16, 2018, 3:45pm

Ah, you have a urbackup Linux server, not Windows.
Looks like you have a database problem.

Try this on the urbackup server–> urbackupsrv repair-database

If that doesn’t fix the database, you may need to reinstall the server software.

You might also check permissions and ownership on the directory and all files in /use/local/var/urbackup

I am out of ideas after that, maybe someone else has other suggestions.

tbaror · March 17, 2018, 5:55pm

Hi ,
you where right it where permission issue , but now i have new issue
the server crash with following errors , please advice
Thanks

2018-03-17 10:52:04: Starting HTTP-Server on port 55414
2018-03-17 10:52:04: HTTP: Server started up successfully!
2018-03-17 10:52:04: WARNING: SQLite: no such table: misc errorcode: 1
2018-03-17 10:52:04: ERROR: Error preparing Query [SELECT tvalue FROM misc WHERE tkey=‘db_version’]: no such table: misc. Retrying in 1s…
2018-03-17 10:52:05: WARNING: SQLite: no such table: misc errorcode: 1
2018-03-17 10:52:05: ERROR: Error preparing Query [SELECT tvalue FROM misc WHERE tkey=‘db_version’]: no such table: misc. Retrying in 1s…
2018-03-17 10:52:06: WARNING: SQLite: no such table: misc errorcode: 1
2018-03-17 10:52:06: ERROR: Error preparing Query [SELECT tvalue FROM misc WHERE tkey=‘db_version’]: no such table: misc. Retrying in 1s…
2018-03-17 10:52:07: WARNING: SQLite: no such table: misc errorcode: 1
2018-03-17 10:52:07: ERROR: Error preparing Query [SELECT tvalue FROM misc WHERE tkey=‘db_version’]: no such table: misc. Retrying in 1s…
2018-03-17 10:52:08: WARNING: SQLite: no such table: misc errorcode: 1
2018-03-17 10:52:08: ERROR: Error preparing Query [SELECT tvalue FROM misc WHERE tkey=‘db_version’]: no such table: misc. Retrying in 1s…
2018-03-17 10:52:10: WARNING: SQLite: no such table: misc errorcode: 1
2018-03-17 10:52:10: ERROR: Error preparing Query [SELECT tvalue FROM misc WHERE tkey=‘db_version’]: no such table: misc
2018-03-17 10:52:10: Importing data…
2018-03-17 10:52:10: WARNING: SQLite: no such table: misc errorcode: 1
2018-03-17 10:52:10: ERROR: Error preparing Query [SELECT tvalue FROM misc WHERE tkey=‘db_version’]: no such table: misc. Retrying in 1s…
2018-03-17 10:52:11: WARNING: SQLite: no such table: misc errorcode: 1
2018-03-17 10:52:11: ERROR: Error preparing Query [SELECT tvalue FROM misc WHERE tkey=‘db_version’]: no such table: misc. Retrying in 1s…
2018-03-17 10:52:12: WARNING: SQLite: no such table: misc errorcode: 1
2018-03-17 10:52:12: ERROR: Error preparing Query [SELECT tvalue FROM misc WHERE tkey=‘db_version’]: no such table: misc. Retrying in 1s…
2018-03-17 10:52:13: WARNING: SQLite: no such table: misc errorcode: 1
2018-03-17 10:52:13: ERROR: Error preparing Query [SELECT tvalue FROM misc WHERE tkey=‘db_version’]: no such table: misc. Retrying in 1s…
2018-03-17 10:52:14: WARNING: SQLite: no such table: misc errorcode: 1
2018-03-17 10:52:14: ERROR: Error preparing Query [SELECT tvalue FROM misc WHERE tkey=‘db_version’]: no such table: misc. Retrying in 1s…
2018-03-17 10:52:15: WARNING: SQLite: no such table: misc errorcode: 1
2018-03-17 10:52:15: ERROR: Error preparing Query [SELECT tvalue FROM misc WHERE tkey=‘db_version’]: no such table: misc
2018-03-17 10:52:15: WARNING: SQLite: no such table: misc errorcode: 1
2018-03-17 10:52:15: ERROR: Error preparing Query [SELECT tvalue FROM misc WHERE tkey=?]: no such table: misc. Retrying in 1s…
2018-03-17 10:52:16: WARNING: SQLite: no such table: misc errorcode: 1
2018-03-17 10:52:16: ERROR: Error preparing Query [SELECT tvalue FROM misc WHERE tkey=?]: no such table: misc. Retrying in 1s…
2018-03-17 10:52:17: WARNING: SQLite: no such table: misc errorcode: 1
2018-03-17 10:52:17: ERROR: Error preparing Query [SELECT tvalue FROM misc WHERE tkey=?]: no such table: misc. Retrying in 1s…
2018-03-17 10:52:18: WARNING: SQLite: no such table: misc errorcode: 1
2018-03-17 10:52:18: ERROR: Error preparing Query [SELECT tvalue FROM misc WHERE tkey=?]: no such table: misc. Retrying in 1s…
2018-03-17 10:52:19: WARNING: SQLite: no such table: misc errorcode: 1
2018-03-17 10:52:19: ERROR: Error preparing Query [SELECT tvalue FROM misc WHERE tkey=?]: no such table: misc. Retrying in 1s…
2018-03-17 10:52:20: WARNING: SQLite: no such table: misc errorcode: 1
2018-03-17 10:52:20: ERROR: Error preparing Query [SELECT tvalue FROM misc WHERE tkey=?]: no such table: misc

02ebz06 · March 17, 2018, 6:00pm

Looks like a database problem.
If the urbackupsrv repair-database doesn’t fix it, you may have to remove/reinstall.
I’m in a similar situation, waiting to here from the experts before removing server and reinstalling it.

tbaror · March 17, 2018, 6:49pm

I did “urbackupsrv repair-database” , didn’t fix it ,are you suggesting to wait little bit more or reinstall it
any way what you suggest as procedure to reinstall coexist with current data backedup?
Thanks again

02ebz06 · March 17, 2018, 7:04pm

I just thought of something,
If you have yours set up to backup the databases, you could try copying the backup database files back to original location.
I think you would have to shutdown the server software first, then restore the files.
My backups have missing files, so I don’t think I can do that.
Check your /var/log/urbackup.log file to see if you have any additional errors.

Reinstalling would most likely destroy the database. If it is corrupt, not a loss anyway.
I don’t know if the software is capable of rebuilding the database from existing backups or not.
I have stopped all my backups and am waiting for advice as I am not a database person.

tbaror · March 17, 2018, 7:10pm

i don’t think i did database backup , unless its set automatically by Urbackup ,in such case where its should be expected to be found?

02ebz06 · March 17, 2018, 7:19pm

Third line from bottom,
Backup files would be in /<Your_Backup_Folder>/urbackup

tbaror · March 19, 2018, 11:23am

ok, Thanks, i restored from backup its works, but now I have new errors on the client side as follows below,
Are those errors could indicate issues with that volume (chkdsk needed)?
thanks

Starting scheduled incremental file backup...
Scanning for changed hard links on volume of "f:\"...
Cannot open file \\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy230\priority\backup\system\mail\201512\r586g\p0620000638.mht to read the file attributes
Cannot open file \\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy230\priority\backup\system\mail\201512\r7ymx\p0458400998.jai to read the file attributes
Cannot open file \\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy230\priority\backup\system\mail\201512\r7ymx\p0537600998.jai to read the file attributes
Cannot open file \\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy230\priority\backup\system\mail\201512\r7ymx\p0735600998.jai to read the file attributes
Cannot open file \\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy230\priority\backup\system\mail\201512\r7ymx\yaron sarf 4.jpg to read the file attributes
Cannot open file \\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy230\priority\backup\system\mail\201512\rf0yl\p0188800991.jai to read the file attributes
Scanning for changed hard links on volume of "c:\"...
Cannot open shadowcopy. Creating new or choosing other.
Removing reference because shadowcopy could not be openend
Not restarting/using existing shadow copy of F:\ because it was not created for image backups/file backups and there is a simultaneous other backup (for_imagebackup=false)
Cannot open shadowcopy. Creating new or choosing other.
Removing reference because shadowcopy could not be openend
Not restarting/using existing shadow copy of F:\ because it was not created for image backups/file backups and there is a simultaneous other backup (for_imagebackup=false)
Starting shadow copy for ".symlink_SqlServerWriter_{A65FAA63-5EA8-4EBC-9DBD-A0C4DB26912A}_5b738dbc8c4a561edbb8c17da3255073_master_files00000000" failed.
Error indexing files 0 of component "master" of writer "SqlServerWriter".
Removing unconfirmed VSS path ".symlink_SqlServerWriter_{A65FAA63-5EA8-4EBC-9DBD-A0C4DB26912A}_d0628e5e35d77472323b31ca37adcd26_master_files00000000" to "C:\Program Files\Microsoft SQL Server\MSSQL12.SPORT_WEBSITE\MSSQL\DATA
Cannot open shadowcopy. Creating new or choosing other.
Removing reference because shadowcopy could not be openend
Restarting shadow copy of F:\ because it was started by this server
backupcom->DeleteSnapshots(dir->ref->ssetid, VSS_OBJECT_SNAPSHOT_SET, TRUE, &dels, &ndels) failed .VSS error code VSS_E_OBJECT_NOT_FOUND
Deleting shadowcopy failed.
Scanning for changed hard links on volume of "F:\"...
Indexing of "F" done. 35011 filesystem lookups 44892 db lookups and 34976 db updates
There was a read error during the last file backup while backing up the file "\\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy227\\Program Files\Microsoft SQL Server\MSSQL11.ESHBEL_PRIORITY\MSSQL\DATA\PROD$ra181214.mdf" at position 1173749760 in backup path "F:" (code: 2). This might have prevented the backup from finishing. If this keeps occuring, please have a look at the system error log and at the disk S.M.A.R.T. values.
SPORT-SQL.sport.local: Loading file list...
SPORT-SQL.sport.local: Calculating file tree differences...
SPORT-SQL.sport.local: Indexing file entries from last backup...
SPORT-SQL.sport.local: Calculating tree difference size...
SPORT-SQL.sport.local: Linking unchanged and loading new files...
Error getting complete file "C0nxYtAh86ljDKmpF2c6|F/priority/backup/system/mail/201707/i3zg0/p0252000775-3.jai" from SPORT-SQL.sport.local. Errorcode: CANNOT_OPEN_FILE (3)
Error getting complete file "C0nxYtAh86ljDKmpF2c6|F/priority/backup/system/mail/201707/i3zg0/p0252000775-4.jai" from SPORT-SQL.sport.local. Errorcode: BASE_DIR_LOST (7)
Client SPORT-SQL.sport.local went offline.
Waiting for file transfers...
Waiting for file hashing and copying threads...
Waiting for metadata download stream to finish
Writing new file list...
Number of copied file entries from last backup is 335094
Transferred 125.184 GB - Average speed: 51.5257 MBit/s
Time taken for backing up client SPORT-SQL.sport.local: 10h 34m 23s
Backup failed


Starting scheduled incremental file backup...
Scanning for changed hard links on volume of "f:\"...
Scanning for changed hard links on volume of "c:\"...
Indexing of "F" done. 12678 filesystem lookups 67234 db lookups and 12610 db updates
SPORT-SQL.sport.local: Loading file list...
SPORT-SQL.sport.local: Calculating file tree differences...
SPORT-SQL.sport.local: Indexing file entries from last backup...
SPORT-SQL.sport.local: Calculating tree difference size...
SPORT-SQL.sport.local: Linking unchanged and loading new files...
Error getting complete file "C0nxYtAh86ljDKmpF2c6|F/priority/backup/system/mail/201712/iljob/308217405.pdf" from SPORT-SQL.sport.local. Errorcode: READ_ERROR (12)
Error getting complete file "C0nxYtAh86ljDKmpF2c6|F/priority/backup/system/mail/201712/iljob/p0197600999.jai" from SPORT-SQL.sport.local. Errorcode: BASE_DIR_LOST (7)
Client SPORT-SQL.sport.local went offline.
Waiting for file transfers...
Waiting for file hashing and copying threads...
Waiting for metadata download stream to finish
Writing new file list...
Number of copied file entries from last backup is 619018
Transferred 175.795 GB - Average speed: 54.792 MBit/s
Time taken for backing up client SPORT-SQL.sport.local: 7h 59m 20s
Backup failed

uroni · March 19, 2018, 12:00pm

ashbeale · March 18, 2019, 11:20am

I have had same issue on two new small servers recently. The server motherboards were Intel and I used the on board RSTe driver for the RAID. I couldn’t get anywhere. Gave up and re-installed the system but used the on board ERST2 driver instead, then all works without any failures. I realise you cannot do this on a production server but worthwhile thinking about the drivers for new machines.