Error in CQuery::Execute

ppalmeiro · July 2, 2013, 4:45pm

Hello community,

I have a UrBackup 1.2 server on an Ubuntu box backing up around 15 windows clients (xp, vista, 7, 2k8)
I haven’t changed any settings and backups have run fine for a while.

Today I noticed the following errors in the logs. (I have my logs set to debug just for paranoia sake…)

The last lines from the log

tail -f /var/log/urbackup.log

2013-07-02 07:42:15: WARNING: HT: Error creating hardlink from "/mnt/nfs/xxxxx/Paris" to "/mnt/nfs/xxxxx/130701-1953/Paris"
2013-07-02 07:42:15: HT: Copying file: "/mnt/nfs/xxxxx/130701-1953/xxxxx/Paris"
2013-07-02 07:42:15: Loading file "conticon.gif"
2013-07-02 07:42:15: ERROR: Error in CQuery::Execute - database disk image is malformed  Stmt: [DELETE FROM files_del WHERE rowid IN ( SELECT rowid FROM files_del LIMIT ? )]
2013-07-02 07:42:16: PT: Hashing file "mesg.0.1.jar"
2013-07-02 07:42:16: ERROR: Error in CQuery::Execute - database disk image is malformed  Stmt: [DELETE FROM files_del WHERE rowid IN ( SELECT rowid FROM files_del LIMIT ? )]
2013-07-02 07:42:16: GT: Loaded file "conticon.gif"
2013-07-02 07:42:16: ERROR: Error in CQuery::Execute - database disk image is malformed  Stmt: [DELETE FROM files_del WHERE rowid IN ( SELECT rowid FROM files_del LIMIT ? )]
2013-07-02 07:42:16: ERROR: Error in CQuery::Execute - database disk image is malformed  Stmt: [DELETE FROM files_del WHERE rowid IN ( SELECT rowid FROM files_del LIMIT ? )]

The output of ps -aux

root@backups:~# ps aux | grep [u]rbackup
urbackup  1030 50.4 22.7 1317368 703900 ?      Sl   Jul01 969:08 /usr/local/sbin/urbackup_srv --daemon --plugin /usr/local/lib/liburbackupserver_urlplugin.so --plugin /usr/local/lib/liburbackupserver_cryptoplugin.so --plugin /usr/local/lib/liburbackupserver_downloadplugin.so --plugin /usr/local/lib/liburbackupserver_fsimageplugin.so --plugin /usr/local/lib/liburbackupserver_httpserver.so --plugin /usr/local/lib/liburbackupserver.so --http_root /usr/local/var/urbackup/www --workingdir /usr/local/var --user urbackup --snapshot_helper /usr/local/bin/urbackup_snapshot_helper --port 55413 --logfile /var/log/urbackup.log --loglevel debug --http_port 55414 --pidfile /var/run/urbackup_srv.pid

After this nothing else is written to the logs…
I have the server configured for file backups every 48 hours. (no image backups)
2 simultaneous jobs, and every thing else is pretty much default values.

The web interface works, sluggish, but works.
In the “Activities” section both jobs are currently running and the file count is decrementing on both jobs.
The ssh session in the VM is painfully slow. (dedicated VM. only backups run on this)

I also noticed that the urbackup_srv process is probably stuck with high cpu usage (of nearly 100%) but oscillating, not fixed at 100% (see output of ps -aux above)
The memory usage is also high, it is consuming the whole 4GB of memory this VM has allocated.

Any toughs on this? How should I proceed?

I’ve read in other threads that a database rebuilt/recreate has worked for others.
Is this the way to go?

Thanks for your support and thanks for a great tool.

Cheers,
P

uroni · July 2, 2013, 6:12pm

With server 1.2.2 you may be able to repair the database via

start_urbackup_server --repair_database

This is largely untested and in another case it destroyed the database --> Create a backup of /var/urbackup/* beforehand.

UrBackup also does a nightly backup of its database per default. Maybe that one is not damaged. See https://urbackup.atlassian.net/wiki/display/US/Troubleshooting+UrBackup+Server+Database for how to check that.

Then it seems to do statistics calculations while backing up.

start_urbackup_server --cleanup 0%

Does this separately and may be faster. (Always shut down UrBackup server before running those commands).

Q: Did you always have those hard link errors?

ppalmeiro · July 3, 2013, 7:27am

Hi uroni,
Thanks for your reply.

I’ll snapshot the VM and test the 1.2.2 suggestions later today and post back the results.

FYI the running jobs completed successfully overnight.

Yes.
I’ve got large logs filled with hard link errors.
The NAS I’m storing the backups in is not very good, but its the only one I can use right now.

Any suggestion to remove/fix those hard link errors?
My backups take a long time to complete, but I’ve always blamed the performance of the NAS…

cheers,
P

uroni · July 11, 2013, 8:49pm

[quote=“ppalmeiro”]Hi uroni,
Yes.
I’ve got large logs filled with hard link errors.
The NAS I’m storing the backups in is not very good, but its the only one I can use right now.

Any suggestion to remove/fix those hard link errors?
My backups take a long time to complete, but I’ve always blamed the performance of the NAS…
[/quote]

Because of those hard link errors probably every one of your incremental file backups is a full backup. So yes, that would slow things down. With regards to the reason: It probably can’t be helped if the NAS does not support hard links.
Maybe you can mount the NAS filesystem via a different method? (NFS instead of CIFS/samba).
You can also create a big file on the NAS (given the NAS supports big files) and create your own file system on it (via losetup).

ppalmeiro · August 9, 2013, 10:53am

Hello everyone,
Just to give some feedback for future reference.

I’v reinstalled the VM and everything works fine since the reinstall.

As an exercise I’ve been trying to repair the damaged database, just to come to a conclusion if it was still recoverable.

[list]
1 Backed up the folder /usr/local/var/urbackup into a tgz
2 I have a 5.1 GB sqlite backup_server.db !!! didn’t knew it could grow so much
3 tried several recovery procedures. none was able to fix the errors. (See references below)
3.1 issuing .dump command outputs an empty file with just a PRAGMA and a COMMIT DDL command
4 PRAGMA integrity_check; found errors in the database.
5 both VACUMM; and reindex; failed to recover the database.
6 tried both processes from the backup but was unable to complete. Killed the process after 3 days.
6.1 the database file was being accessed sporadically.
7 eventually gave up and assumed once the backup_server.db gets corrupted, a recover from backup is in order…
[/list:u:1ji0g8u6]

References:
[1]

[2]

[3]

Trying reindex;

root@backups:/usr/local/var/urbackup# sqlite3 backup_server.db
SQLite version 3.7.7 2011-06-23 19:49:22
Enter ".help" for instructions
Enter SQL statements terminated with a ";"
sqlite> .tables
assoc_images     clients          del_stats        logs
backup_images    clients_hist     files            misc
backups          clients_hist_id  files_del
sqlite> PRAGMA journal_mode=delete;
delete
sqlite> PRAGMA integrity_check;  

*** in database main ***
On tree page 1070080 cell 5: invalid page number 541475574
rowid 9977815 missing from index files_idx
rowid 9978235 missing from index files_idx
rowid 14571544 missing from index files_idx
rowid 14571964 missing from index files_idx
rowid 14572385 missing from index files_idx
wrong # of entries in index files_idx
Error: database disk image is malformed
sqlite>
sqlite> reindex;
	
	--- process killed after 3 days

Trying VACUUM;

root@backups:/usr/local/var/urbackup# sqlite3 backup_server.db
SQLite version 3.7.7 2011-06-23 19:49:22
Enter ".help" for instructions
Enter SQL statements terminated with a ";"
sqlite> .tables
assoc_images     clients          del_stats        logs
backup_images    clients_hist     files            misc
backups          clients_hist_id  files_del
sqlite> PRAGMA journal_mode=delete;
delete
sqlite> PRAGMA integrity_check;  

*** in database main ***
On tree page 1070080 cell 5: invalid page number 541475574
rowid 9977815 missing from index files_idx
rowid 9978235 missing from index files_idx
rowid 14571544 missing from index files_idx
rowid 14571964 missing from index files_idx
rowid 14572385 missing from index files_idx
wrong # of entries in index files_idx
Error: database disk image is malformed
sqlite>
sqlite> VACUUM;
	
	--- process killed after 3 days

Trying .dump;

root@backups:/usr/local/var/urbackup# sqlite3 backup_server.db
SQLite version 3.7.7 2011-06-23 19:49:22
Enter ".help" for instructions
Enter SQL statements terminated with a ";"
sqlite> .tables
assoc_images     clients          del_stats        logs
backup_images    clients_hist     files            misc
backups          clients_hist_id  files_del
sqlite> PRAGMA journal_mode=delete;
delete
sqlite> PRAGMA integrity_check;  

*** in database main ***
On tree page 1070080 cell 5: invalid page number 541475574
rowid 9977815 missing from index files_idx
rowid 9978235 missing from index files_idx
rowid 14571544 missing from index files_idx
rowid 14571964 missing from index files_idx
rowid 14572385 missing from index files_idx
wrong # of entries in index files_idx
Error: database disk image is malformed
sqlite>
sqlite> .output backup_server.sql
sqlite> .dump;
sqlite> .quit  

root@backups:/usr/local/var/urbackup# cat backup_server.sql
PRAGMA foreign_keys=OFF;
BEGIN TRANSACTION;
COMMIT

cheers,
palmeiro