Can you have a look at the client debug log at the end of a file backup?
that sould be this one…
2016-05-12 11:12:31: WARNING: File "/mnt/Backups/jumpfwdb.hotline.local/160512-1112/.hashes/urbackup_backup_scripts/mariadbdump.sql" has wrong size. Should=828 is=1064. Error writing metadata to file. -1
Anything I can do about the MDB_NOTFOUND error to get the server working again?
This morning we’ve got lot of Image backups failed with these messages :
Info 13/05/16 04:00 Starting incremental image backup...
Info 13/05/16 04:18 Basing image backup on last incremental or full image backup
Info 13/05/16 04:18 Creating writable snapshot of previous image backup...
Errors13/05/16 04:54 Received unknown block number: -8824501502147462418. Stopping image backup.
Info 13/05/16 04:54 Transferred 681.879 MB - Average speed: 2.67429 MBit/s
Info 13/05/16 04:54 Time taken for backing up client SV217: 53m 28s
Errors13/05/16 04:54 Backup failedUrBackup 2.0.17 / Debian 8 / BTRFS storage / clients 2.0.19
And incremental file backup on some anothers VM :
Info 12/05/16 22:13 SV408: Linking unchanged and loading new files..
Errors 13/05/16 01:32 Error getting file patch for "JjumQSQ8qzkb3VU1JEid|isagiwf/B443469.COW/CRELEVE.DB" from SV408. Errorcode: TIMEOUT (2)
Errors 13/05/16 01:32 Client SV408 went offline.
Info 13/05/16 03:58 Waiting for file transfers...
Info 13/05/16 03:58 Client had timeout. Retrying backup soon...
Info 13/05/16 03:58 Waiting for file hashing and copying threads...
Info 13/05/16 03:58 Waiting for metadata download stream to finish
Info 13/05/16 03:58 Saving file metadata...
Info 13/05/16 03:58 Writing new file list...
Info 13/05/16 03:58 Number of readded file entries is 279296
Info 13/05/16 03:58 Transferred 223.326 MB - Average speed: 154.432 KBit/s
Info 13/05/16 03:58 (Before compression: 361.953 MB ratio: 1.62074)
Info 13/05/16 03:58 1.39176 GB of files were already present on the server and did not need to be tran sferred
Info 13/05/16 03:58 Time taken for backing up client SV408: 5h 58m 1s
Errors 13/05/16 03:58 Backup failedin /var/log/urbackup.log we have :
2016-05-13 03:48:14: WARNING: Block hash wrong. Getting whole block. currpos=4194304
2016-05-13 03:58:45: ERROR: Backup failed
2016-05-13 04:25:24: WARNING: Reading from parent hash file failed (May be caused by a volume with increased size)
2016-05-13 04:25:41: ERROR: Error decompressing stream(2): -3 Err: invalid code lengths set
2016-05-13 04:25:45: WARNING: Reading from parent hash file failed (May be caused by a volume with increased size)
2016-05-13 04:25:45: ERROR: Received unknown block number: -4952054592502743627. Stopping image backup.
2016-05-13 04:25:45: ERROR: Backup failed
2016-05-13 04:25:52: WARNING: Exponential backoff: Waiting at least 40m before next image backup
2016-05-13 04:34:46: ERROR: Error decompressing stream(2): -3 Err: invalid block type
2016-05-13 04:34:47: WARNING: Reading from parent hash file failed (May be caused by a volume with increased size)
2016-05-13 04:34:48: WARNING: Reading from parent hash file failed (May be caused by a volume with increased size)
2016-05-13 04:53:59: ERROR: Error decompressing stream(2): -3 Err: invalid block type
2016-05-13 04:54:01: WARNING: Reading from parent hash file failed (May be caused by a volume with increased size)
2016-05-13 04:54:03: WARNING: Checksum for image block wrong. Retrying...
2016-05-13 04:54:07: WARNING: Checksum for image block wrong. Retrying...
2016-05-13 04:54:10: ERROR: Received unknown block number: -8017918401077419915. Stopping image backup.
2016-05-13 04:54:10: ERROR: Backup failed
2016-05-13 04:54:10: ERROR: Received unknown block number: -7717330964154679248. Stopping image backup.
2016-05-13 04:54:10: ERROR: Backup failed
2016-05-13 04:54:11: ERROR: Received unknown block number: -8824501502147462418. Stopping image backup.
2016-05-13 04:54:11: ERROR: Backup failed
2016-05-13 04:54:12: WARNING: Exponential backoff: Waiting at least 40m before next image backup
2016-05-13 04:54:17: WARNING: Exponential backoff: Waiting at least 40m before next image backup
2016-05-13 04:54:17: WARNING: Exponential backoff: Waiting at least 40m before next image backup
2016-05-13 04:54:18: ERROR: Error sending flush request
2016-05-13 04:54:20: ERROR: Error sending flush request
2016-05-13 05:29:34: ERROR: Received unknown block number: -8410401778416327579. Stopping image backup.
2016-05-13 05:29:37: ERROR: Backup failed
2016-05-13 05:29:44: WARNING: Exponential backoff: Waiting at least 1h 20m before next image backup
2016-05-13 05:51:38: WARNING: Reading from parent hash file failed (May be caused by a volume with increased size)
root@urbackup:~# Regards,
getting corrupted double-linked list again while running urbackupsrv remove-unkown…
trace in gdb:
2016-05-13 08:37:27: Delete file index entry 1002367
2016-05-13 08:37:27: Delete file index entry 1002368
2016-05-13 08:37:27: Delete file index entry 1002369
*** Error in `/usr/sbin/urbackupsrv': corrupted double-linked list: 0x0000000000caf340 ***
Program received signal SIGABRT, Aborted.
[Switching to Thread 0x7ffff1ffb700 (LWP 29897)]
0x00007ffff6a61067 in __GI_raise (sig=sig@entry=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:56
56 ../nptl/sysdeps/unix/sysv/linux/raise.c: Datei oder Verzeichnis nicht gefunden.
(gdb) bt
#0 0x00007ffff6a61067 in __GI_raise (sig=sig@entry=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:56
#1 0x00007ffff6a62448 in __GI_abort () at abort.c:89
#2 0x00007ffff6a9f1b4 in __libc_message (do_abort=do_abort@entry=1, fmt=fmt@entry=0x7ffff6b94530 "*** Error in `%s': %s: 0x%s ***\n") at ../sysdeps/posix/libc_fatal.c:175
#3 0x00007ffff6aa498e in malloc_printerr (action=1, str=0x7ffff6b9060c "corrupted double-linked list", ptr=<optimized out>) at malloc.c:4996
#4 0x00007ffff6aa5923 in _int_free (av=0x7ffff6dd1620 <main_arena>, p=<optimized out>, have_lock=0) at malloc.c:3996
#5 0x00000000008fbd0e in mdb_env_close1.part ()
#6 0x00000000008fc800 in mdb_env_close ()
#7 0x000000000067cd49 in LMDBFileIndex::commit_transaction_internal(bool) ()
#8 0x0000000000680b34 in FileIndex::operator()() ()
#9 0x000000000044dc76 in CPoolThread::operator()() ()
#10 0x000000000041aba6 in thread_helper_f(void*) ()
#11 0x00007ffff6ddf0a4 in start_thread (arg=0x7ffff1ffb700) at pthread_create.c:309
#12 0x00007ffff6b1487d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111
(gdb)Since it appeared conistently accross clients and without you installing a new version, could it be that it really is a network or memory problem? ( memcheck86 + try another networking device? )
UrBackup is running into a VM (Proxmox KVM, 4 vCPUS, 6 Gb RAM, virtio devices for network and drives).
Maybe a network problem over the WAN …
So i’ve updated the server to 2.0.18 and rebooted all clients
For the moment there is a “urbackupsrv remove-unknown” running, which is very long (few hours)
Here is the content of my /var/urbackup/ directory :
root@urbackup:~# ll -hR /var/urbackup/
/var/urbackup/:
total 24G
-rw-r--r-- 1 urbackup urbackup 29 mai 13 10:33 backupfolder
-rw-r--r-- 1 urbackup urbackup 7,6G mai 13 11:44 backup_server.db
-rw-r--r-- 1 urbackup urbackup 16G mai 13 11:53 backup_server_files.db
-rw-r--r-- 1 urbackup urbackup 54M mai 13 11:53 backup_server_files.db-journal
-rw-r--r-- 1 urbackup urbackup 50M mai 13 10:45 backup_server_link_journal.db
-rw-r--r-- 1 urbackup urbackup 4,0K mai 13 10:33 backup_server_links.db
-rw-r--r-- 1 urbackup urbackup 154K mai 13 10:45 backup_server_settings.db
-rwxr-x--- 1 urbackup urbackup 53M mai 12 12:51 clientlist_b_236.ub
-rwxr-x--- 1 urbackup urbackup 1,2M mai 12 22:32 clientlist_b_237.ub
-rwxr-x--- 1 urbackup urbackup 4,9M mai 13 00:20 clientlist_b_238.ub
-rwxr-x--- 1 urbackup urbackup 6,2M mai 13 00:31 clientlist_b_239.ub
-rwxr-x--- 1 urbackup urbackup 11M mai 13 02:53 clientlist_b_240.ub
-rwxr-x--- 1 urbackup urbackup 19M mai 13 03:34 clientlist_b_241.ub
-rwxr-x--- 1 urbackup urbackup 16M mai 13 03:58 clientlist_b_242.ub
-rwxr-x--- 1 urbackup urbackup 19M mai 13 03:38 clientlist_b_243.ub
-rwxr-x--- 1 urbackup urbackup 21M mai 13 03:57 clientlist_b_244.ub
-rwxr-x--- 1 urbackup urbackup 23M mai 13 04:14 clientlist_b_245.ub
-rwxr-x--- 1 urbackup urbackup 30M mai 13 05:05 clientlist_b_246.ub
-rwxr-x--- 1 urbackup urbackup 29M mai 13 04:36 clientlist_b_247.ub
-rwxr-x--- 1 urbackup urbackup 33M mai 13 02:34 clientlist_b_248.ub
-rwxr-x--- 1 urbackup urbackup 15M avril 25 23:57 clientlist_b_41.ub
-rwxr-x--- 1 urbackup urbackup 19M avril 26 23:49 clientlist_b_56.ub
-rwxr-x--- 1 urbackup urbackup 28M avril 27 00:45 clientlist_b_59.ub
-rwxr-x--- 1 urbackup urbackup 15M avril 27 07:39 clientlist_b_62.ub
-rwxr-x--- 1 urbackup urbackup 0 avril 27 22:40 clientlist_b_75.ub
-rwxr-x--- 1 urbackup urbackup 0 avril 28 00:00 clientlist_b_84.ub
-rwxr-x--- 1 urbackup urbackup 0 avril 28 19:41 clientlist_b_86.ub
drwxr-x--- 2 urbackup urbackup 4,0K mars 29 14:56 fileindex
-rw-r--r-- 1 urbackup urbackup 391 mars 29 14:56 server_ident_ecdsa409k1.priv
-rw-r--r-- 1 urbackup urbackup 436 mars 29 14:56 server_ident_ecdsa409k1.pub
-rw-r--r-- 1 urbackup urbackup 23 mars 29 14:56 server_ident.key
-rw-r--r-- 1 urbackup urbackup 334 mars 29 14:56 server_ident.priv
-rw-r--r-- 1 urbackup urbackup 442 mars 29 14:56 server_ident.pub
-rw-r--r-- 1 urbackup urbackup 20 mars 29 14:56 server_token.key
-rwxr-x--- 1 urbackup urbackup 0 mai 9 12:48 server_version_info.properties
-rw-r--r-- 1 urbackup urbackup 31M mai 11 22:18 UrBackupUpdate.exe
-rw-r--r-- 1 urbackup urbackup 9,5M mai 11 22:19 UrBackupUpdateLinux.sh
-rw-r--r-- 1 urbackup urbackup 102 mai 11 22:20 UrBackupUpdateLinux.sig2
-rw-r--r-- 1 urbackup urbackup 40 mai 11 22:20 UrBackupUpdate.sig
-rw-r--r-- 1 urbackup urbackup 102 mai 11 22:12 UrBackupUpdate.sig2
-rw-r--r-- 1 urbackup urbackup 3 mai 11 22:23 version.txt
/var/urbackup/fileindex:
total 651M
-rw-r--r-- 1 urbackup urbackup 651M mai 13 11:53 backup_server_files_index.lmdb
-rw-r--r-- 1 urbackup urbackup 8,0K mai 13 11:53 backup_server_files_index.lmdb-lock
root@urbackup:~#The Database check integrity is also very long.
Is it a normal behaviour ?
I’ll made some new tests after the maintenance tasks finished.
Regards,
Is it using veth on the KVM host?
I don’t know … How can i check this ?
Hmm I think veth is only for containers, so no need to check.
@tarakesh If 2.0.19 does not fix this it would be great if you run it with debug symbols and/or in valgrind (edit: okay it already shows the symbols but I wonder why it does not show the lines…) .
Upgraded to 2.0.19 and looks like the MDB_NOTFOUND issue is fixed. Will report any other issues. Thanks!
debug.log (58.9 KB)
Configuration: Server 2.0.19 [Debian 8.3] Client 2.0.19 [Win 2012R2]
File backups keep stopping and resuming.
Server is reporting:
Each log has the following:
Errors 05/13/16 11:13 Error getting file patch for “yxgqdYXHak6mkfz9IhQK|FCNS8001/VOLUME.fid” from CLIENT. Errorcode: TIMEOUT (2)
Errors 05/13/16 11:13 Client CLIENT went offline.
Errors 05/13/16 11:19 Backup failed
Server 2.0.20 may fix this.
uroni,
Will you update the backend and frontend on Github?
Thanks,
1 Like
Configuration: Server 2.0.20 [Debian 8.3] Client 2.0.19 [Windows 10]
Just setup a new client and when opening access/restore backups from either the taskbar icon or right clicking on a folder gives:
However, when trying to reproduce this problem on my test Win10 PC, I don’t get this error (it’s been upgraded several times though). Maybe something to do with a new setup?
Configuration: Server 2.0.20 [Debian 8.3] Client 2.0.19 [Windows 10]
[Fixed] Full/incremental file backups not backing up any files (backup size: 0 bytes). No error messages:
debug.log (109.0 KB)
Update: enabled client debug log, ran backup & attached log.
Issue Fixed: I found there were a bunch of paths entered in “Excluded files” “Included Files” and “Default directories to backup.” Clearing out all these fields fixed the issue:
Hi
Still have this morning some image backups failed with errors :
2016-05-16 06:16:42: ERROR: Received unknown block number: -9089383771842594186. Stopping image backup.
2016-05-16 06:16:42: ERROR: Received unknown block number: -3478617815858713695. Stopping image backup.
2016-05-16 06:16:54: ERROR: Backup failed
2016-05-16 06:16:54: ERROR: Backup failed
2016-05-16 06:16:56: ERROR: Received unknown block number: -4498439552181179963. Stopping image backup.
2016-05-16 06:16:57: ERROR: Received unknown block number: -1655073315993157562. Stopping image backup.
2016-05-16 06:16:57: ERROR: Error decompressing stream(2): -3 Err: invalid distance code
2016-05-16 06:16:58: ERROR: Backup failed
2016-05-16 06:17:01: ERROR: Backup failed
2016-05-16 06:17:04: ERROR: Error decompressing stream(2): -3 Err: invalid block type
2016-05-16 06:17:05: ERROR: Received unknown block number: -7558363926305325349. Stopping image backup.
2016-05-16 06:17:05: ERROR: Backup failedDebian 8 (2.0.20) / BTRFS storage [(4.4.0) / client Winows 2012 R2 (2.0.19)
Regards,
I think I can make it retry on those errors but I want to verify this is a hardware or driver issue. What Linux kernel version does your Proxmox host use and what network device?
Okay
Hardware Proxmox host is a DELL PE 2950 with Broadcom network devices
Linux version 4.4.6-1-pve (root@elsa) (gcc version 4.9.2 (Debian 4.9.2-10) ) #1 SMP Thu Apr 21 11:25:40 CEST 2016
proxmox-ve: 4.2-48 (running kernel: 4.4.6-1-pve)
pve-manager: 4.2-2 (running version: 4.2-2/725d76f0)lspci
...
03:00.0 Ethernet controller: Broadcom Corporation NetXtreme II BCM5708 Gigabit Ethernet (rev 12)
07:00.0 Ethernet controller: Broadcom Corporation NetXtreme II BCM5708 Gigabit Ethernet (rev 12)
...Regards,