Urbackup Server stopping

Server
1

I’m running urbackup on a ubuntu 14.04 server and we have around 5-6 Windows servers being backed up through the internet. However I keep checking in the morning and keep seeing it has stopped. I have enabled debug and can see it seems to get a “Patch corrupt” before stopping,

2016-06-17 23:16:06: GT: Linked file "023f71263cc8d101dd000000c80ec410.amd64_microsoft-windows-lsa_31bf3856ad364e35_6.1.7601.23452_none_04ccbb5c8caad84b_sspisrv.dll_90c23c68" 2016-06-17 23:16:06: GT: Linked file "0262b9eb72c7d101e30000004805880e.x86_microsoft-windows-msauditevtlog_31bf3856ad364e35_6.1.7601.23452_none_c9a60f64efefa39b_msobjs.dll_052c8a60" 2016-06-17 23:16:07: GT: Linked file "02770d433cc8d10190010000c80ec410.wow64_microsoft-windows-smss_31bf3856ad364e35_6.1.7601.23418_none_1542c4557d4c2a10.manifest" 2016-06-17 23:16:08: Connecting to target service... 2016-06-17 23:16:08: Established internet connection. Service=0 2016-06-17 23:16:08: Authed+capa for client 'example-server1.com' (token auth) - 1 spare connections 2016-06-17 23:16:08: Connecting to target service... 2016-06-17 23:16:08: Established internet connection. Service=0 2016-06-17 23:16:08: Authed+capa for client 'flaydemouse-server2.ha247.co.uk' (token auth) - 1 spare connections 2016-06-17 23:16:09: GT: Linked file "02770d433cc8d10191010000c80ec410.wow64_microsoft-windows-smss_31bf3856ad364e35_6.1.7601.23418_none_1542c4557d4c2a10_apisetschema.dll_d4a833e3" 2016-06-17 23:16:09: GT: Linked file "02db25e872c7d101a90000004805880e.x86_microsoft-windows-c..ityclient.resources_31bf3856ad364e35_6.1.7601.23452_en-us_6722ec011756e812.manifest" 2016-06-17 23:16:09: GT: File "02ec08db72c7d101320000004805880e.$$_system32_en-us_429cd25484dc6f94.cdf-ms" not found via hash. Loading file... 2016-06-17 23:16:09: GT: Linked file "japaanese-themed-gardens-at-compton-acres-dorset;-.jpg" 2016-06-17 23:16:10: GT: File "japaanese-themed-gardens-at-compton-acres-dorset;-.jpg" not found via hash. Loading file... 2016-06-17 23:16:10: No old file for "japaanese-themed-gardens-at-compton-acres-dorset;-.jpg" 2016-06-17 23:16:10: Loading file "japaanese-themed-gardens-at-compton-acres-dorset;-.jpg" 2016-06-17 23:16:10: GT: Loaded file "japaanese-themed-gardens-at-compton-acres-dorset;-.jpg" 2016-06-17 23:16:10: PT: Hashing file "japaanese-themed-gardens-at-compton-acres-dorset;-.jpg" 2016-06-17 23:16:10: HT: Copying file: "/mnt/backup/urbackup/example-server1.com/160617-2200/D/htdocs/www.bestinhorticulture.co.uk/media/c/pg/1/1448894605/rc/3273/2182/90/japaanese-themed-gardens-at-compton-acres-dorset;-.jpg" 2016-06-17 23:16:10: ERROR: Fatal error writing to file in writeFileRepeat. Write error in Chunked File transfer. 2016-06-17 23:16:10: Whole block. currpos=1572864 block_for_chunk_start=1572864 chunk_start=1572864 2016-06-17 23:16:10: Successfull. Returning filesize 1819648 2016-06-17 23:16:10: GT: Loaded file "amd64_microsoft-windows-security-msagent_31bf3856ad364e35_6.1.7601.17514_none_a1089c578d98ec83_msagent.dll_94e1418e" 2016-06-17 23:16:10: Loading file patch for "702349c5b78f9a04_blobs.bin" 2016-06-17 23:16:10: PT: Hashing file "amd64_microsoft-windows-security-msagent_31bf3856ad364e35_6.1.7601.17514_none_a1089c578d98ec83_msagent.dll_94e1418e" 2016-06-17 23:16:13: ERROR: Patch corrupt. file_pos=18944 next_header.patch_off=524288 next_header.patch_size=0 tr=32768 size=18944 filesize=1819648

Any ideas what is causing urbackup server to stop?

2

Again urbackup server process stopped last night with the last entry being ERROR: Patch corrupt. Can anyone help me with this issue?

2016-06-20 22:05:56: GT: Linked file "424d7f3405c9d10171000000f410bc0f.amd64_microsoft-windows-g..licy-base.resources_31bf3856ad364e35_6.1.7601.23452_en-us_1fb6cc35a0c5cfc7_gpapi.dll.mui_ef0a9748" 2016-06-20 22:05:56: Copying 1001 files from tmp table... 2016-06-20 22:05:56: Connecting to target service... 2016-06-20 22:05:56: Established internet connection. Service=0 2016-06-20 22:05:56: Authed+capa for client 'inetcom-server2.ha247.co.uk' (token auth) - 1 spare connections 2016-06-20 22:05:56: Connecting to target service... 2016-06-20 22:05:56: Established internet connection. Service=0 2016-06-20 22:05:56: Authed+capa for client 'theonlywaytogo-server1.ha247.co.uk' (token auth) - 1 spare connections 2016-06-20 22:05:56: Connecting to target service... 2016-06-20 22:05:56: Established internet connection. Service=0 2016-06-20 22:05:56: Authed+capa for client 'professionalproperties-server3.ha247.co.uk' (token auth) - 1 spare connections 2016-06-20 22:05:58: Connecting to target service... 2016-06-20 22:05:58: Established internet connection. Service=0 2016-06-20 22:05:58: Authed+capa for client 'fball-server1.ha247.co.uk' (token auth) - 1 spare connections 2016-06-20 22:05:58: Connecting to target service... 2016-06-20 22:05:58: Established internet connection. Service=0 2016-06-20 22:05:58: Authed+capa for client 'inetcom-server1.ha247.co.uk' (token auth) - 1 spare connections 2016-06-20 22:05:59: Connecting to target service... 2016-06-20 22:05:59: Established internet connection. Service=0 2016-06-20 22:05:59: Authed+capa for client 'netbusiness-server1.ha247.co.uk' (token auth) - 1 spare connections 2016-06-20 22:05:59: Connecting to target service... 2016-06-20 22:05:59: Established internet connection. Service=0 2016-06-20 22:05:59: Authed+capa for client 'flaydemouse-server2.ha247.co.uk' (token auth) - 1 spare connections 2016-06-20 22:06:01: done. 2016-06-20 22:06:01: GT: Linked file "425d7ba4cec9d101e3010000080f7401.wow64_microsoft-windows-gdi_31bf3856ad364e35_6.1.7601.23453_none_12aaf3aebec5d8b3_atmlib.dll_fe5ca5c9" 2016-06-20 22:06:01: GT: File "4269792073c7d101d80100004805880e.$$_system32_21f9a9c4a2f8b514.cdf-ms" not found via hash. Loading file... 2016-06-20 22:06:01: GT: Linked file "42874ccf97cad101de0100003c06100b.amd64_microsoft-windows-gdi_31bf3856ad364e35_6.1.7601.23453_none_0856495c8a6516b8_atmfd.dll_ff796bf0" 2016-06-20 22:06:01: GT: Linked file "42e8ca95cec9d101a0010000080f7401.amd64_microsoft-windows-c..integrity.resources_31bf3856ad364e35_6.1.7601.23418_en-us_57e7f2a77d144f08.manifest" 2016-06-20 22:06:01: GT: Linked file "42e8ca95cec9d101a1010000080f7401.amd64_microsoft-windows-c..integrity.resources_31bf3856ad364e35_6.1.7601.23418_en-us_57e7f2a77d144f08_ci.dll.mui_76757f43" 2016-06-20 22:06:01: ERROR: Fatal error writing to file in writeFileRepeat. Write error in Chunked File transfer. 2016-06-20 22:06:01: Whole block. currpos=1572864 block_for_chunk_start=1572864 chunk_start=1572864 2016-06-20 22:06:01: Successfull. Returning filesize 1819648 2016-06-20 22:06:01: GT: Loaded file "amd64_microsoft-windows-security-msagent_31bf3856ad364e35_6.1.7601.17514_none_a1089c578d98ec83_msagent.dll_94e1418e" 2016-06-20 22:06:01: Loading file patch for "702349c5b78f9a04_blobs.bin" 2016-06-20 22:06:01: PT: Hashing file "amd64_microsoft-windows-security-msagent_31bf3856ad364e35_6.1.7601.17514_none_a1089c578d98ec83_msagent.dll_94e1418e" 2016-06-20 22:06:02: Old filesize=238653099 2016-06-20 22:06:02: ERROR: Patch corrupt. file_pos=18944 next_header.patch_off=524288 next_header.patch_size=0 tr=32768 size=18944 filesize=1819648

3

That is probably causing it. Unfortunately 1.4.x doesn’t log the system error code there. Have a look at dmesg and check if there is enough free space.

4

Plenty of disk space and nothing in dmesg?

5

I guess you could get the system error code by attaching strace (strace -f -p {urbackup_pid}).

6

Here is the strace, still no idea why its randomly stopping?

POLLIN}, {fd=166, events=POLLIN}], 9, 10) = 0 (Timeout) [pid 21143] poll([{fd=139, events=POLLIN}, {fd=127, events=POLLIN}, {fd=90, events=POLLIN}, {fd=156, events=POLLIN}, {fd=184, events=POLLIN}, {fd=152, events=POLLIN}, {fd=158, events=POLLIN}, {fd=160, events= POLLIN}, {fd=166, events=POLLIN}], 9, 10) = 0 (Timeout) [pid 21143] poll([{fd=139, events=POLLIN}, {fd=127, events=POLLIN}, {fd=90, events=POLLIN}, {fd=156, events=POLLIN}, {fd=184, events=POLLIN}, {fd=152, events=POLLIN}, {fd=158, events=POLLIN}, {fd=160, events= POLLIN}, {fd=166, events=POLLIN}], 9, 10 <unfinished ...> [pid 21066] <... poll resumed> ) = 0 (Timeout) [pid 21066] poll([{fd=23, events=POLLIN}], 1, 1000 <unfinished ...> [pid 21143] <... poll resumed> ) = 0 (Timeout) [pid 21143] poll([{fd=139, events=POLLIN}, {fd=127, events=POLLIN}, {fd=90, events=POLLIN}, {fd=156, events=POLLIN}, {fd=184, events=POLLIN}, {fd=152, events=POLLIN}, {fd=158, events=POLLIN}, {fd=160, events= POLLIN}, {fd=166, events=POLLIN}], 9, 10) = 0 (Timeout) [pid 21143] poll([{fd=139, events=POLLIN}, {fd=127, events=POLLIN}, {fd=90, events=POLLIN}, {fd=156, events=POLLIN}, {fd=184, events=POLLIN}, {fd=152, events=POLLIN}, {fd=158, events=POLLIN}, {fd=160, events= POLLIN}, {fd=166, events=POLLIN}], 9, 10) = 0 (Timeout) [pid 21143] poll([{fd=139, events=POLLIN}, {fd=127, events=POLLIN}, {fd=90, events=POLLIN}, {fd=156, events=POLLIN}, {fd=184, events=POLLIN}, {fd=152, events=POLLIN}, {fd=158, events=POLLIN}, {fd=160, events= POLLIN}, {fd=166, events=POLLIN}], 9, 10) = 0 (Timeout) [pid 21143] poll([{fd=139, events=POLLIN}, {fd=127, events=POLLIN}, {fd=90, events=POLLIN}, {fd=156, events=POLLIN}, {fd=184, events=POLLIN}, {fd=152, events=POLLIN}, {fd=158, events=POLLIN}, {fd=160, events= POLLIN}, {fd=166, events=POLLIN}], 9, 10Process 21066 detached

7

Just an update, we have changed from hashing to raw, and it hasn’t died yet.