UrBackup Server 2.0.21 beta (updated 6x)/Client 2.0.19 beta (updated 6x)

The major changes are described in the blog: http://blog.urbackup.org/223/new-in-urbackup-2-0-x

The portable Linux client doesn’t have C+±exception support (yet). In my tests everything was functional but this is something that must be resolved before releasing a non-beta version.

Changes with server 2.0.21 beta

  • Prevent client list deletion during backup
  • Run incremental image backup also if full image backup is disabled
  • Halved (meta-data) pipe file read timeout
  • Nightly cleanup of SYSVOL/ESP images associated with incomplete images
  • Use correct identity in channel thread
  • Only hard link files with at least 2K size
  • Increase max number of file index readers from 127 to 4094
  • Reconnect and retry if image backup block number is corrupted
  • Update output file size only when writing out patch and not earlier
  • Do not reconnect from file queuing because this causes double frees (introduced in last version)
  • Force client re-authentication on address change (e.g. from Internet to local)

Changes with server 2.0.20 beta

  • Fix: Use tar file name instead of last file name in log output
  • Reconnect if file request fails and retry

Changes with server 2.0.19 beta

  • Fix saving meta-data for files in meta-data
  • Changed log level of “Saved metadata of…” to debug
  • Fix issues with file entry index
  • Reintroduced the missing syncing before full database checkpoint
  • Prevent shared mutex writer starvation
  • Prevent recursive read locking of shared mutex
  • Resize hash output to correct size if it is lower than what was already output
  • Use tar file name instead of last file name in log output
  • Log file download corruptions

Changes with server 2.0.18 beta

  • Do not re-created script and meta-data transfers when client is restarted and server reconnects
  • Treat SQLITE_PROTOCOL error like SQLITE_BUSY (retry query)
  • Removed systemd task limit in systemd unit file
  • New file backup status “completed with issues” and OS and client version persistence

Changes with server 2.0.17 beta

  • Do not verify client side hashes on incomplete files
  • Manually resolve relative vhd paths to work around Windows path limit

Changes with server 2.0.16 beta

  • Handle shadow copy failures with 1.4.x client
  • Improved handling of case where snapshot removal is delayed because of still ongoing meta-data transfers
  • Improved logging when stopping meta-data transfer
  • Improved file meta-data shutdown procedure

Changes with server 2.0.15 beta

  • Fix setting non-admin password from command line
  • Reset exponential backoff also if backup failed with e.g. timeout
  • Fixed file index racing condition
  • Load whole block regardless of block hash if reading for hash fails
  • Fix os_set_file_time for FreeBSD directories
  • Wait for at least 10s before hard shutdown of meta-data transfer
  • Log about download with sparse extents
  • Warning instead of assert if file size is wrong in meta-data
  • Retry getting VSS log data
  • Re-authenticate with client after client update
  • Symbolic link creation check on status screen

Changes with client 2.0.19 beta

  • Lowered idle timeout for file upload from 60h to 1h
  • Free file after 1 min instead of 1 hour if idle

Changes with client 2.0.18 beta

  • Do not re-created script and meta-data transfers when client is restarted and server reconnects
  • Correctly cleanup file meta-data stream if interrupted and not reconnected

Changes with client 2.0.17 beta

  • Fix share referencing error after timeout
  • Revert: Fix share referencing error after reconnection

Changes with client 2.0.16 beta

  • Fix share referencing error after reconnection causing hang in snapshot removal

Changes with client 2.0.15 beta

  • Handle case where volume size is not block size (4k) aligned

Changes with client 2.0.14 beta

  • Fix SYSCONFDIR variable replacement in Linux scripts
  • Improved handling of case where snapshot removal is delayed because of still ongoing meta-data transfers

Changes with client 2.0.13 beta

  • Fix line endings in postgres backup scripts
  • List VSS provider after VSS provider error
  • Do not delete excluded/not included files/directories when restoring
  • Do not try to create windows volume as directory during restore
  • Correctly open alternative file for renaming later during restore
  • Various file restore fixes
  • Restore all files when restore is done via client regardless of user access tokens
  • Perform incremental indexes after unfinished full indexes

Todo

  • UEFI/GPT testing

Compatibility with prior versions

  • 2.x server with 1.4.x client full compatibility (please report issues)
  • 2.x client with 1.4.x server works only in local network mode (not via internet mode)
  • Older client/server combinations may work but were not tested
  • 1.x restore does not work with 2.x servers (improved login method)

Upgrade process

As always: Replace the executables (via the installers) and the database of the server/client will be updated on first running it. As always downgrading the database version after upgrading it is not possible, so you should backup the old database files especially since this is a beta.

Because of the improved file de-duplication and statistics calculation the largest server table has to be completely rebuild. This may take a few hours depending on how many file entries you have. It will show the progress on the web interface but is not usable during the upgrade process.

Linux notes:

  • The wrapper scripts start_urbackup_server and start_urbackup_client have been removed. Please use the executable directly
  • The executable has been renamed to urbackupsrv (from urbackup_srv), the client to urbackupclientbackend (from urbackup_client)
  • There is a new command line interface for the client urbackupclientctl
  • All the plugins are now statically linked into one executable. This simplifies the compilation, debugging and packaging on Linux

Run the UrBackup server on Linux with e.g. urbackupsrv run --loglevel debug

Downloads

Could you please update update3.urbackup.org with last client 2.0.14 in order to make possible automatic client upgrades ?

Thanks.

Regards

Configuration: Server 2.0.16 [Debian 8.3]
Problem: Server stopping, cannot open admin web page

I’ve had the server stop with no error message, but maybe this will help:

/var/log/urbackup.log:

2016-05-09 05:48:29: WARNING: Shutting down (Signal 15)

[Upgrade to 2.0.16 here]

2016-05-09 05:50:01: ERROR: Error downloading server version information: HTTP response code said error(ec=22), The requested URL returned error: 404 Not Found
2016-05-09 05:50:54: ERROR: Error in update: verify_sig_err
2016-05-09 05:50:54: ERROR: Timeout: In client update
2016-05-09 05:58:49: WARNING: Restarting shadow copy of D:\ because it was started by this server
2016-05-09 06:01:19: WARNING: Restarting shadow copy of D:\ because it was started by this server
2016-05-09 06:50:03: ERROR: Error downloading server version information: HTTP response code said error(ec=22), The requested URL returned error: 404 Not Found
2016-05-09 06:50:05: ERROR: No permission to access “/data/urbackup/CLIENT/160508-0352”
2016-05-09 06:50:05: WARNING: Warning: Directory doesn’t exist: “/data/urbackup/CLIENT/160508-0352”
^C

systemctl status urbackupsrv

urbackupsrv.service - LSB: Server for doing backups
Loaded: loaded (/etc/init.d/urbackupsrv)
Active: active (exited) since Mon 2016-05-09 05:48:59 PDT; 1h 9min ago

When this happens, I have to run systemctl restart urbackupsrv to get working again

Edit: This also happened in 2.0.15.
Edit2:

If you are using the the debian package the dmesg urbackupsrv line might be helpful.

[ 82.969981] Installing knfsd (copyright © 1996 okir@monad.swb.de).
[ 3442.962218] [sched_delayed] sched: RT throttling activated
[ 5518.720050] INFO: task fbackup write:1679 blocked for more than 120 seconds.
[ 5518.720090] Not tainted 3.16.0-4-amd64 #1
[ 5518.720116] “echo 0 > /proc/sys/kernel/hung_task_timeout_secs” disables this message.
[ 5518.720145] fbackup write D ffff88002e5f84a8 0 1679 1 0x00000000
[ 5518.720151] ffff88002e5f8050 0000000000000086 0000000000012f00 ffff88001d177fd8
[ 5518.720153] 0000000000012f00 ffff88002e5f8050 ffff88007f80f590 ffff88001d177cd8
[ 5518.720154] ffff88007f80f594 ffff88002e5f8050 00000000ffffffff ffff88007f80f598
[ 5518.720155] Call Trace:
[ 5518.720160] [] ? schedule_preempt_disabled+0x25/0x70
[ 5518.720162] [] ? __mutex_lock_slowpath+0xd3/0x1c0
[ 5518.720163] [] ? mutex_lock+0x1b/0x2a
[ 5518.720205] [] ? btrfs_log_inode_parent+0x3f1/0x4f0 [btrfs]
[ 5518.720214] [] ? btrfs_log_dentry_safe+0x3c/0x60 [btrfs]
[ 5518.720221] [] ? btrfs_sync_file+0x16b/0x2f0 [btrfs]
[ 5518.720227] [] ? btrfs_file_write_iter+0x1d2/0x4c0 [btrfs]
[ 5518.720230] [] ? new_sync_write+0x74/0xa0
[ 5518.720232] [] ? vfs_write+0xb2/0x1f0
[ 5518.720233] [] ? vfs_read+0xed/0x170
[ 5518.720234] [] ? SyS_write+0x42/0xa0
[ 5518.720236] [] ? SyS_lseek+0x43/0xa0
[ 5518.720238] [] ? system_call_fast_compare_end+0x10/0x15
[ 5518.720244] INFO: task fbackup load:1912 blocked for more than 120 seconds.
[ 5518.720261] Not tainted 3.16.0-4-amd64 #1
[ 5518.720272] “echo 0 > /proc/sys/kernel/hung_task_timeout_secs” disables this message.
[ 5518.720290] fbackup load D ffff880019a2d908 0 1912 1 0x00000000
[ 5518.720292] ffff880019a2d4b0 0000000000000086 0000000000012f00 ffff880014bb3fd8
[ 5518.720293] 0000000000012f00 ffff880019a2d4b0 ffff88003728d2f8 ffff880014bb3cd8
[ 5518.720294] ffff88003728d2fc ffff880019a2d4b0 00000000ffffffff ffff88003728d300
[ 5518.720295] Call Trace:
[ 5518.720297] [] ? schedule_preempt_disabled+0x25/0x70
[ 5518.720298] [] ? __mutex_lock_slowpath+0xd3/0x1c0
[ 5518.720299] [] ? mutex_lock+0x1b/0x2a
[ 5518.720306] [] ? btrfs_log_inode_parent+0xce/0x4f0 [btrfs]
[ 5518.720312] [] ? btrfs_log_dentry_safe+0x3c/0x60 [btrfs]
[ 5518.720318] [] ? btrfs_sync_file+0x16b/0x2f0 [btrfs]
[ 5518.720323] [] ? btrfs_file_write_iter+0x1d2/0x4c0 [btrfs]
[ 5518.720325] [] ? new_sync_write+0x74/0xa0
[ 5518.720327] [] ? vfs_write+0xb2/0x1f0
[ 5518.720328] [] ? SyS_write+0x42/0xa0
[ 5518.720330] [] ? system_call_fast_compare_end+0x10/0x15
[ 5518.720332] INFO: task fbackup load:1990 blocked for more than 120 seconds.
[ 5518.720349] Not tainted 3.16.0-4-amd64 #1
[ 5518.720359] “echo 0 > /proc/sys/kernel/hung_task_timeout_secs” disables this message.
[ 5518.720377] fbackup load D ffff880041a02df8 0 1990 1 0x00000000
[ 5518.720379] ffff880041a029a0 0000000000000086 0000000000012f00 ffff880054c73fd8
[ 5518.720380] 0000000000012f00 ffff880041a029a0 ffff88007f80f590 ffff880054c73cd8
[ 5518.720381] ffff88007f80f594 ffff880041a029a0 00000000ffffffff ffff88007f80f598
[ 5518.720382] Call Trace:
[ 5518.720383] [] ? schedule_preempt_disabled+0x25/0x70
[ 5518.720384] [] ? __mutex_lock_slowpath+0xd3/0x1c0
[ 5518.720386] [] ? mutex_lock+0x1b/0x2a
[ 5518.720392] [] ? btrfs_log_inode_parent+0x3f1/0x4f0 [btrfs]
[ 5518.720397] [] ? btrfs_log_dentry_safe+0x3c/0x60 [btrfs]
[ 5518.720402] [] ? btrfs_sync_file+0x16b/0x2f0 [btrfs]
[ 5518.720407] [] ? btrfs_file_write_iter+0x1d2/0x4c0 [btrfs]
[ 5518.720409] [] ? new_sync_write+0x74/0xa0
[ 5518.720411] [] ? vfs_write+0xb2/0x1f0
[ 5518.720412] [] ? SyS_write+0x42/0xa0
[ 5518.720413] [] ? system_call_fast_compare_end+0x10/0x15
[ 5518.720415] INFO: task fbackup load:2479 blocked for more than 120 seconds.
[ 5518.720431] Not tainted 3.16.0-4-amd64 #1
[ 5518.720442] “echo 0 > /proc/sys/kernel/hung_task_timeout_secs” disables this message.
[ 5518.720460] fbackup load D ffff88000b03c828 0 2479 1 0x00000000
[ 5518.720461] ffff88000b03c3d0 0000000000000086 0000000000012f00 ffff880000efffd8
[ 5518.720462] 0000000000012f00 ffff88000b03c3d0 ffff88003728d2f8 ffff880000effcd8
[ 5518.720463] ffff88003728d2fc ffff88000b03c3d0 00000000ffffffff ffff88003728d300
[ 5518.720464] Call Trace:
[ 5518.720465] [] ? schedule_preempt_disabled+0x25/0x70
[ 5518.720467] [] ? __mutex_lock_slowpath+0xd3/0x1c0
[ 5518.720468] [] ? mutex_lock+0x1b/0x2a
[ 5518.720474] [] ? btrfs_log_inode_parent+0xce/0x4f0 [btrfs]
[ 5518.720478] [] ? btrfs_log_dentry_safe+0x3c/0x60 [btrfs]
[ 5518.720483] [] ? btrfs_sync_file+0x16b/0x2f0 [btrfs]
[ 5518.720488] [] ? btrfs_file_write_iter+0x1d2/0x4c0 [btrfs]
[ 5518.720490] [] ? new_sync_write+0x74/0xa0
[ 5518.720492] [] ? vfs_write+0xb2/0x1f0
[ 5518.720493] [] ? SyS_write+0x42/0xa0
[ 5518.720494] [] ? system_call_fast_compare_end+0x10/0x15
[ 5998.593164] INFO: task fbackup load:1912 blocked for more than 120 seconds.
[ 5998.593190] Not tainted 3.16.0-4-amd64 #1
[ 5998.593201] “echo 0 > /proc/sys/kernel/hung_task_timeout_secs” disables this message.
[ 5998.593220] fbackup load D ffff880019a2d908 0 1912 1 0x00000000
[ 5998.593225] ffff880019a2d4b0 0000000000000086 0000000000012f00 ffff880014bb3fd8
[ 5998.593226] 0000000000012f00 ffff880019a2d4b0 ffff88007f80f590 ffff880014bb3cd8
[ 5998.593227] ffff88007f80f594 ffff880019a2d4b0 00000000ffffffff ffff88007f80f598
[ 5998.593229] Call Trace:
[ 5998.593235] [] ? schedule_preempt_disabled+0x25/0x70
[ 5998.593237] [] ? __mutex_lock_slowpath+0xd3/0x1c0
[ 5998.593239] [] ? mutex_lock+0x1b/0x2a
[ 5998.593264] [] ? btrfs_log_inode_parent+0x3f1/0x4f0 [btrfs]
[ 5998.593271] [] ? btrfs_record_root_in_trans+0x52/0x70 [btrfs]
[ 5998.593278] [] ? btrfs_log_dentry_safe+0x3c/0x60 [btrfs]
[ 5998.593284] [] ? btrfs_sync_file+0x16b/0x2f0 [btrfs]
[ 5998.593290] [] ? btrfs_file_write_iter+0x1d2/0x4c0 [btrfs]
[ 5998.593293] [] ? new_sync_write+0x74/0xa0
[ 5998.593295] [] ? vfs_write+0xb2/0x1f0
[ 5998.593296] [] ? vfs_read+0xed/0x170
[ 5998.593297] [] ? SyS_write+0x42/0xa0
[ 5998.593299] [] ? SyS_lseek+0x43/0xa0
[ 5998.593301] [] ? system_call_fast_compare_end+0x10/0x15
[ 5998.593304] INFO: task fbackup load:1990 blocked for more than 120 seconds.
[ 5998.593321] Not tainted 3.16.0-4-amd64 #1
[ 5998.593332] “echo 0 > /proc/sys/kernel/hung_task_timeout_secs” disables this message.
[ 5998.593350] fbackup load D ffff880041a02df8 0 1990 1 0x00000000
[ 5998.593352] ffff880041a029a0 0000000000000086 0000000000012f00 ffff880054c73fd8
[ 5998.593353] 0000000000012f00 ffff880041a029a0 ffff88003728d2f8 ffff880054c73cd8
[ 5998.593354] ffff88003728d2fc ffff880041a029a0 00000000ffffffff ffff88003728d300
[ 5998.593355] Call Trace:
[ 5998.593357] [] ? schedule_preempt_disabled+0x25/0x70
[ 5998.593358] [] ? __mutex_lock_slowpath+0xd3/0x1c0
[ 5998.593360] [] ? mutex_lock+0x1b/0x2a
[ 5998.593367] [] ? btrfs_log_inode_parent+0xce/0x4f0 [btrfs]
[ 5998.593372] [] ? btrfs_log_dentry_safe+0x3c/0x60 [btrfs]
[ 5998.593377] [] ? btrfs_sync_file+0x16b/0x2f0 [btrfs]
[ 5998.593382] [] ? btrfs_file_write_iter+0x1d2/0x4c0 [btrfs]
[ 5998.593385] [] ? new_sync_write+0x74/0xa0
[ 5998.593387] [] ? vfs_write+0xb2/0x1f0
[ 5998.593388] [] ? SyS_write+0x42/0xa0
[ 5998.593389] [] ? system_call_fast_compare_end+0x10/0x15
[ 5998.593391] INFO: task fbackup load:2479 blocked for more than 120 seconds.
[ 5998.593407] Not tainted 3.16.0-4-amd64 #1
[ 5998.593418] “echo 0 > /proc/sys/kernel/hung_task_timeout_secs” disables this message.
[ 5998.593436] fbackup load D ffff88000b03c828 0 2479 1 0x00000000
[ 5998.593438] ffff88000b03c3d0 0000000000000086 0000000000012f00 ffff880000efffd8
[ 5998.593439] 0000000000012f00 ffff88000b03c3d0 ffff88003728d2f8 ffff880000effcd8
[ 5998.593439] ffff88003728d2fc ffff88000b03c3d0 00000000ffffffff ffff88003728d300
[ 5998.593440] Call Trace:
[ 5998.593442] [] ? schedule_preempt_disabled+0x25/0x70
[ 5998.593443] [] ? __mutex_lock_slowpath+0xd3/0x1c0
[ 5998.593445] [] ? mutex_lock+0x1b/0x2a
[ 5998.593451] [] ? btrfs_log_inode_parent+0xce/0x4f0 [btrfs]
[ 5998.593456] [] ? btrfs_log_dentry_safe+0x3c/0x60 [btrfs]
[ 5998.593461] [] ? btrfs_sync_file+0x16b/0x2f0 [btrfs]
[ 5998.593466] [] ? btrfs_file_write_iter+0x1d2/0x4c0 [btrfs]
[ 5998.593468] [] ? new_sync_write+0x74/0xa0
[ 5998.593470] [] ? vfs_write+0xb2/0x1f0
[ 5998.593471] [] ? SyS_write+0x42/0xa0
[ 5998.593472] [] ? system_call_fast_compare_end+0x10/0x15
[13196.689834] INFO: task fbackup load:1990 blocked for more than 120 seconds.
[13196.689866] Not tainted 3.16.0-4-amd64 #1
[13196.689878] “echo 0 > /proc/sys/kernel/hung_task_timeout_secs” disables this message.
[13196.689897] fbackup load D ffff880041a02df8 0 1990 1 0x00000000
[13196.689901] ffff880041a029a0 0000000000000086 0000000000012f00 ffff880054c73fd8
[13196.689902] 0000000000012f00 ffff880041a029a0 ffff88007f80f590 ffff880054c73cd8
[13196.689903] ffff88007f80f594 ffff880041a029a0 00000000ffffffff ffff88007f80f598
[13196.689904] Call Trace:
[13196.689910] [] ? schedule_preempt_disabled+0x25/0x70
[13196.689911] [] ? __mutex_lock_slowpath+0xd3/0x1c0
[13196.689913] [] ? mutex_lock+0x1b/0x2a
[13196.689938] [] ? btrfs_log_inode_parent+0x3f1/0x4f0 [btrfs]
[13196.689946] [] ? btrfs_record_root_in_trans+0x52/0x70 [btrfs]
[13196.689953] [] ? btrfs_log_dentry_safe+0x3c/0x60 [btrfs]
[13196.689960] [] ? btrfs_sync_file+0x16b/0x2f0 [btrfs]
[13196.689966] [] ? btrfs_file_write_iter+0x1d2/0x4c0 [btrfs]
[13196.689968] [] ? futex_wake+0x6f/0x120
[13196.689971] [] ? new_sync_write+0x74/0xa0
[13196.689973] [] ? vfs_write+0xb2/0x1f0
[13196.689974] [] ? SyS_write+0x42/0xa0
[13196.689976] [] ? system_call_fast_compare_end+0x10/0x15
[13196.689978] INFO: task fbackup load:2479 blocked for more than 120 seconds.
[13196.689994] Not tainted 3.16.0-4-amd64 #1
[13196.690005] “echo 0 > /proc/sys/kernel/hung_task_timeout_secs” disables this message.
[13196.690024] fbackup load D ffff88000b03c828 0 2479 1 0x00000000
[13196.690025] ffff88000b03c3d0 0000000000000086 0000000000012f00 ffff880000efffd8
[13196.690027] 0000000000012f00 ffff88000b03c3d0 ffff88003728d2f8 ffff880000effcd8
[13196.690028] ffff88003728d2fc ffff88000b03c3d0 00000000ffffffff ffff88003728d300
[13196.690029] Call Trace:
[13196.690031] [] ? schedule_preempt_disabled+0x25/0x70
[13196.690032] [] ? __mutex_lock_slowpath+0xd3/0x1c0
[13196.690033] [] ? mutex_lock+0x1b/0x2a
[13196.690040] [] ? btrfs_log_inode_parent+0xce/0x4f0 [btrfs]
[13196.690045] [] ? btrfs_log_dentry_safe+0x3c/0x60 [btrfs]
[13196.690051] [] ? btrfs_sync_file+0x16b/0x2f0 [btrfs]
[13196.690056] [] ? btrfs_file_write_iter+0x1d2/0x4c0 [btrfs]
[13196.690058] [] ? zap_page_range+0xfa/0x130
[13196.690060] [] ? new_sync_write+0x74/0xa0
[13196.690062] [] ? vfs_write+0xb2/0x1f0
[13196.690063] [] ? SyS_write+0x42/0xa0
[13196.690065] [] ? device_not_available+0x1e/0x30
[13196.690066] [] ? system_call_fast_compare_end+0x10/0x15
[13316.658101] INFO: task fbackup load:1990 blocked for more than 120 seconds.
[13316.658124] Not tainted 3.16.0-4-amd64 #1
[13316.658136] “echo 0 > /proc/sys/kernel/hung_task_timeout_secs” disables this message.
[13316.658154] fbackup load D ffff880041a02df8 0 1990 1 0x00000000
[13316.658157] ffff880041a029a0 0000000000000086 0000000000012f00 ffff880054c73fd8
[13316.658158] 0000000000012f00 ffff880041a029a0 ffff88007f80f590 ffff880054c73cd8
[13316.658159] ffff88007f80f594 ffff880041a029a0 00000000ffffffff ffff88007f80f598
[13316.658161] Call Trace:
[13316.658170] [] ? schedule_preempt_disabled+0x25/0x70
[13316.658172] [] ? __mutex_lock_slowpath+0xd3/0x1c0
[13316.658173] [] ? mutex_lock+0x1b/0x2a
[13316.658200] [] ? btrfs_log_inode_parent+0x3f1/0x4f0 [btrfs]
[13316.658206] [] ? btrfs_record_root_in_trans+0x52/0x70 [btrfs]
[13316.658212] [] ? btrfs_log_dentry_safe+0x3c/0x60 [btrfs]
[13316.658219] [] ? btrfs_sync_file+0x16b/0x2f0 [btrfs]
[13316.658224] [] ? btrfs_file_write_iter+0x1d2/0x4c0 [btrfs]
[13316.658227] [] ? futex_wake+0x6f/0x120
[13316.658231] [] ? new_sync_write+0x74/0xa0
[13316.658232] [] ? vfs_write+0xb2/0x1f0
[13316.658234] [] ? SyS_write+0x42/0xa0
[13316.658236] [] ? system_call_fast_compare_end+0x10/0x15
[378156.446427] traps: http dynamic re[7296] general protection ip:4238a4 sp:7ff7e1fe9fa0 error:0 in urbackupsrv[400000+628000]
[379018.966070] BTRFS info (device sdb): disk space caching is enabled
[721344.964857] urbackupsrv[13635]: segfault at 2beb880 ip 0000000002beb880 sp 00007f3bef7f5d78 error 15
[801155.120311] urbackupsrv[17238]: segfault at 2140880 ip 0000000002140880 sp 00007fc6c27fbd78 error 15

It just stopped again, but nothing new in dmesg |grep urbackupsrv:

[378156.446427] traps: http dynamic re[7296] general protection ip:4238a4 sp:7ff7e1fe9fa0 error:0 in urbackupsrv[400000+628000]
[721344.964857] urbackupsrv[13635]: segfault at 2beb880 ip 0000000002beb880 sp 00007f3bef7f5d78 error 15
[801155.120311] urbackupsrv[17238]: segfault at 2140880 ip 0000000002140880 sp 00007fc6c27fbd78 error 15

I haven’t rebooted since the last few upgrades, so I’ll do that and report back if it stops again.

Points to nowhere, unfortunately.

You could put it into debug log mode (in /etc/default/urbackupsrv) and/or run it in a debugger after compiling it (run with gdb --args urbackupsrv run -v debug – after crash enter bt), or configure it such that it creates core dumps and send me those.

Hi,

I seem to be getting endless Meta Data Streams on a couple of 2.0.16beta clients

16/05/10 09:59 DEBUG Loading “urbackup/FILE_METADATA|bDP9Sijri7SLoddXhJUm|3954”. Loaded 31.3779 KB at 0 Bit/s16/05/10 10:00 DEBUG Loading “urbackup/FILE_METADATA|bDP9Sijri7SLoddXhJUm|3954”. Loaded 31.3789 KB at 0 Bit/s16/05/10 10:02 DEBUG Loading “urbackup/FILE_METADATA|bDP9Sijri7SLoddXhJUm|3954”. Loaded 31.3809 KB at 0 Bit/s16/05/10 10:03 DEBUG Loading “urbackup/FILE_METADATA|bDP9Sijri7SLoddXhJUm|3954”. Loaded 31.3818 KB at 0 Bit/s16/05/10 10:04 DEBUG Loading “urbackup/FILE_METADATA|bDP9Sijri7SLoddXhJUm|3954”. Loaded 31.3828 KB at 0 Bit/s16/05/10 10:05 DEBUG Loading “urbackup/FILE_METADATA|bDP9Sijri7SLoddXhJUm|3954”. Loaded 31.3838 KB at 0 Bit/s16/05/10 10:06 DEBUG Loading “urbackup/FILE_METADATA|bDP9Sijri7SLoddXhJUm|3954”. Loaded 31.3848 KB at 0 Bit/s16/05/10 10:07 DEBUG Loading “urbackup/FILE_METADATA|bDP9Sijri7SLoddXhJUm|3954”. Loaded 31.3857 KB at 0 Bit/s16/05/10 10:08 DEBUG Loading “urbackup/FILE_METADATA|bDP9Sijri7SLoddXhJUm|3954”. Loaded 31.3867 KB at 0 Bit/s16/05/10 10:09 DEBUG Loading “urbackup/FILE_METADATA|bDP9Sijri7SLoddXhJUm|3954”. Loaded 31.3877 KB at 0 Bit/s16/05/10 10:10 DEBUG Loading “urbackup/FILE_METADATA|bDP9Sijri7SLoddXhJUm|3954”. Loaded 31.3887 KB at 0 Bit/s16/05/10 10:11 DEBUG Loading “urbackup/FILE_METADATA|bDP9Sijri7SLoddXhJUm|3954”. Loaded 31.3896 KB at 0 Bit/s16/05/10 10:12 DEBUG Loading “urbackup/FILE_METADATA|bDP9Sijri7SLoddXhJUm|3954”. Loaded 31.3906 KB at 0 Bit/s16/05/10 10:13 DEBUG Loading “urbackup/FILE_METADATA|bDP9Sijri7SLoddXhJUm|3954”. Loaded 31.3916 KB at 0 Bit/s16/05/10 10:14 DEBUG Loading “urbackup/FILE_METADATA|bDP9Sijri7SLoddXhJUm|3954”. Loaded 31.3926 KB at 0 Bit/s16/05/10 10:15 DEBUG Loading “urbackup/FILE_METADATA|bDP9Sijri7SLoddXhJUm|3954”. Loaded 31.3936 KB at 0 Bit/s16/05/10 10:16 DEBUG Loading “urbackup/FILE_METADATA|bDP9Sijri7SLoddXhJUm|3954”. Loaded 31.3945 KB at 0 Bit/s16/05/10 10:17 DEBUG Loading “urbackup/FILE_METADATA|bDP9Sijri7SLoddXhJUm|3954”. Loaded 31.3955 KB at 0 Bit/s16/05/10 10:18 DEBUG Loading “urbackup/FILE_METADATA|bDP9Sijri7SLoddXhJUm|3954”. Loaded 31.3965 KB at 0 Bit/s16/05/10 10:19 DEBUG Loading “urbackup/FILE_METADATA|bDP9Sijri7SLoddXhJUm|3954”. Loaded 31.3975 KB at 0 Bit/s

hey… problems with samba on Windows server?

Sorry, 2.0.16 made this worse not better. Hopefully it is fixed with client 2.0.17 now.

Hi Uroni,

Just had the same errors with 2.0.17beta server/client.

Ok i restarted the clients and re ran the incr backup and all completed without Metadata stream glitch

Same problem here with debian 8 server 2.0.17 BTRFS storage and clients v 2.0.17 :

11/05/16 10:54  	DEBUG  	Loading "urbackup/FILE_METADATA|JjumQSQ8qzkb3VU1JEid|221". Loaded 3.01417 MB at 32 Bit/s
11/05/16 10:55  	DEBUG  	Loading "urbackup/FILE_METADATA|JjumQSQ8qzkb3VU1JEid|221". Loaded 3.01417 MB at 0 Bit/s
11/05/16 10:56  	DEBUG  	Loading "urbackup/FILE_METADATA|JjumQSQ8qzkb3VU1JEid|221". Loaded 3.01417 MB at 0 Bit/s
11/05/16 10:57  	DEBUG  	Loading "urbackup/FILE_METADATA|JjumQSQ8qzkb3VU1JEid|221". Loaded 3.01417 MB at 0 Bit/s
11/05/16 10:58  	DEBUG  	Loading "urbackup/FILE_METADATA|JjumQSQ8qzkb3VU1JEid|221". Loaded 3.01417 MB at 0 Bit/s
11/05/16 10:59  	DEBUG  	Loading "urbackup/FILE_METADATA|JjumQSQ8qzkb3VU1JEid|221". Loaded 3.01417 MB at 0 Bit/s
11/05/16 11:00  	DEBUG  	Loading "urbackup/FILE_METADATA|JjumQSQ8qzkb3VU1JEid|221". Loaded 3.01417 MB at 0 Bit/s
11/05/16 11:01  	DEBUG  	Loading "urbackup/FILE_METADATA|JjumQSQ8qzkb3VU1JEid|221". Loaded 3.01418 MB at 0 Bit/s
11/05/16 11:02  	DEBUG  	Loading "urbackup/FILE_METADATA|JjumQSQ8qzkb3VU1JEid|221". Loaded 3.01418 MB at 0 Bit/s
11/05/16 11:03  	DEBUG  	Loading "urbackup/FILE_METADATA|JjumQSQ8qzkb3VU1JEid|221". Loaded 3.01418 MB at 0 Bit/s
11/05/16 11:04  	DEBUG  	Loading "urbackup/FILE_METADATA|JjumQSQ8qzkb3VU1JEid|221". Loaded 3.01418 MB at 0 Bit/s
11/05/16 11:05  	DEBUG  	Loading "urbackup/FILE_METADATA|JjumQSQ8qzkb3VU1JEid|221". Loaded 3.01418 MB at 0 Bit/s
11/05/16 11:06  	DEBUG  	Loading "urbackup/FILE_METADATA|JjumQSQ8qzkb3VU1JEid|221". Loaded 3.01418 MB at 0 Bit/s
11/05/16 11:07  	DEBUG  	Loading "urbackup/FILE_METADATA|JjumQSQ8qzkb3VU1JEid|221". Loaded 3.01418 MB at 0 Bit/s
11/05/16 11:08  	DEBUG  	Loading "urbackup/FILE_METADATA|JjumQSQ8qzkb3VU1JEid|221". Loaded 3.01418 MB at 0 Bit/s
11/05/16 11:09  	DEBUG  	Loading "urbackup/FILE_METADATA|JjumQSQ8qzkb3VU1JEid|221". Loaded 3.01418 MB at 0 Bit/s
11/05/16 11:10  	DEBUG  	Loading "urbackup/FILE_METADATA|JjumQSQ8qzkb3VU1JEid|221". Loaded 3.01418 MB at 0 Bit/s
11/05/16 11:11  	DEBUG  	Loading "urbackup/FILE_METADATA|JjumQSQ8qzkb3VU1JEid|221". Loaded 3.01418 MB at 0 Bit/s
11/05/16 11:12  	DEBUG  	Loading "urbackup/FILE_METADATA|JjumQSQ8qzkb3VU1JEid|221". Loaded 3.01419 MB at 0 Bit/s
11/05/16 11:13  	DEBUG  	Loading "urbackup/FILE_METADATA|JjumQSQ8qzkb3VU1JEid|221". Loaded 3.01419 MB at 0 Bit/s
11/05/16 11:14  	DEBUG  	Loading "urbackup/FILE_METADATA|JjumQSQ8qzkb3VU1JEid|221". Loaded 3.01419 MB at 0 Bit/s
11/05/16 11:15  	DEBUG  	Loading "urbackup/FILE_METADATA|JjumQSQ8qzkb3VU1JEid|221". Loaded 3.01419 MB at 0 Bit/s
11/05/16 11:16  	DEBUG  	Loading "urbackup/FILE_METADATA|JjumQSQ8qzkb3VU1JEid|221". Loaded 3.01419 MB at 0 Bit/s

Is there a way to force the backup to finish ?

Thanks.

Regards,

Okay so the Stop button doesn’t work but restarting the “UrBackup Client Service for Backups” on the Windows client did the trick. Backup succeed but with error :

Error informing client about metadata stream end. Errorcode: TIMEOUT (2)
Error getting file metadata. Errorcode: BASE_DIR_LOST (7)

Regards,

Urbackup server 2.0.17 beta rpm for CentOS 7 https://yadi.sk/d/_iVhX7wTrdX93

Let’s see if it is fixed completely with 2.0.18 now.

Got this after upgrading to server 2.0.18:

[ 242.116567] BTRFS info (device sdb): The free space cache file (559985721344) is invalid. skip it

[ 242.189118] BTRFS info (device sdb): The free space cache file (561059463168) is invalid. skip it

[ 242.307136] BTRFS info (device sdb): The free space cache file (562133204992) is invalid. skip it

[ 657.659983] fileindex write[776]: segfault at 0 ip 000000000066f051 sp 00007efdeefb1430 error 4 in urbackupsrv[400000+639000]

2016-05-11 13:14:41: WARNING: File entry with id 4629523 with filesize 28672 found in entry index while deleting, but should be there. The file entry index may be damaged.
2016-05-11 13:14:41: WARNING: File entry with id 4632831 with filesize 1572864 found in entry index while deleting, but should be there. The file entry index may be damaged.
2016-05-11 13:14:41: WARNING: File entry with id 4632832 with filesize 32768 found in entry index while deleting, but should be there. The file entry index may be damaged.
2016-05-11 13:15:00: ERROR: LMDB: Failed to delete data (MDB_NOTFOUND: No matching key/data pair found)
2016-05-11 13:15:00: ERROR: LMDB: Failed to delete data (MDB_NOTFOUND: No matching key/data pair found)
2016-05-11 13:15:00: ERROR: LMDB: Failed to delete data (MDB_NOTFOUND: No matching key/data pair found)
2016-05-11 13:15:08: ERROR: LMDB had error during increase (on commit). Aborting…

Update:

I also see this in the activity log just before the server crashes:

05/11/16 16:17 INFO Waiting for file hashing and copying threads…
05/11/16 16:17 INFO Waiting for metadata download stream to finish
05/11/16 16:17 INFO Writing new file list…
05/11/16 16:18 DEBUG Some metadata was missing
05/11/16 16:18 INFO Number of copyied file entries from last backup is 3
05/11/16 16:18 DEBUG Client disconnected while backing up. Copying partial file…
05/11/16 16:18 INFO Transferred 33.6981 MB - Average speed: 200.216 KBit/s
05/11/16 16:18 INFO (Before compression: 96.5814 MB ratio: 2.86608)
05/11/16 16:18 INFO 13.3232 GB of files were already present on the server and did not need to be transferred
05/11/16 16:18 DEBUG Script does not exist urbackup/post_incr_filebackup
05/11/16 16:18 INFO Time taken for backing up client CLIENT: 45m 57s
05/11/16 16:18 ERROR Backup failed

getting this error since update to latest versions…
madiadb dump is enabled in /usr/local/etc/urbackup/madiadbdump.conf
initial backup was fine. but incremental throws this

Errors 12.05.16 11:12 Writing metadata to /mnt/Backups/jumpfwdb.hotline.local/160512-1112/.hashes/urbackup_backup_scripts/mariadbdump.sql failed
Errors 12.05.16 11:13 Fatal error during backup. Backup not completed
Errors 12.05.16 11:13 FATAL: Backup failed because of disk problems
Errors 12.05.16 11:13 Backup failed

I can guarantee that the Harddisks are absolutly fine…

There should be a log message previous to Writing metadata to... in the global log file (/var/log/urbackup.log). Could you post that one?

Hi,

I use the prefilebackup.bat and postfilebackup.bat on clients to stop and start/run scripts before and after backups since around 2.0.16beta client the postfilebackup.bat is not running after the backup completes however the prefilebackup.bat runs.

anyone else having this issue?