Jump to content
flickerfly

Ubuntu server - slow connection, failing backup

Recommended Posts

I've been having trouble with one of our many Ubuntu machines backing up. For awhile it just would fail to release the client and I'd have to go in and restart the rcl service frequently. This became more frequent and now I simply can't run backups. It'll run for about 4 hours and fail, locking the daemon, blocking further backups and the message "reserved for Immediate Backup" is reported when I run retrocpl. I can try again after stopping and starting the rcl service.

 

Is what I'm seeing connection problems of some sort? Any idea what is disrupting the connection?

 

I've turned up the logging which resulted in the following. This machine also have several virtual NICs eth0:0-9 so I bound it to the IP on eth0. Since this problem began I have upgraded to Ubuntu 12.04 in hopes something old was in the way. I've tried simply uninstalling the software and reinstalling it, reacquainting it with the Retrospect server.

 
These log entries are from the daemon started with the follwing command /usr/local/dantz/client/retroclient -ip 10.x.x.11 -log 55 -daemon. The file I find them in is /var/log/retroclient.log.

1381998420: connTCPConnection: conn = -188741752, code = 300, tid = 20, count = 540
1381998420: connTransMsg: writing message 300, 20, cpSX
1381998420: transPiper: writing code = 300, tid = 20, count = 540
1381998420: transPiper: writing code = 300, tid = 20, count = 540
1381998420: connTCPConnection: conn = -188741752, code = 300, tid = 20, count = 540
1381998420: connTransMsg: writing message 300, 20, cpSX
1381998420: transPiper: writing code = 300, tid = 20, count = 540
1381998420: transPiper: writing code = 300, tid = 20, count = 540
1381998420: connTCPConnection: conn = -188741752, code = 300, tid = 20, count = 540
1381998420: connTransMsg: writing message 300, 20, cpSX
1381998420: transPiper: writing code = 300, tid = 20, count = 540
1381998420: transPiper: writing code = 300, tid = 20, count = 540
1381998420: connTCPConnection: conn = -188741752, code = 300, tid = 20, count = 540
1381998420: connTransMsg: writing message 300, 20, cpSX
1381998420: transPiper: writing code = 300, tid = 20, count = 540
1381998420: transPiper: writing code = 300, tid = 20, count = 540
1381998420: connTCPConnection: conn = -188741752, code = 300, tid = 20, count = 540
1381998420: connTransMsg: writing message 300, 20, cpSX
1381998420: transPiper: writing code = 300, tid = 20, count = 540
1381998420: transPiper: writing code = 300, tid = 20, count = 540
1381998420: connTCPConnection: conn = -188741752, code = 300, tid = 20, count = 540
1381998420: connTransMsg: writing message 300, 20, cpSX
1381998420: transPiper: writing code = 300, tid = 20, count = 540
1381998420: transPiper: writing code = 300, tid = 20, count = 540
1381998420: connTCPConnection: conn = -188741752, code = 300, tid = 20, count = 540
1381998420: connTransMsg: writing message 300, 20, cpSX
1381998420: transPiper: writing code = 300, tid = 20, count = 540
1381998420: transPiper: writing code = 300, tid = 20, count = 540
1381998420: connTCPConnection: conn = -188741752, code = 110, tid = 20, count = 0
1381998420: connTcpConnection: client stop (20)
1381998420: TransStop: send = 1, result = 0
1381998420: TransStop: killing transaction (20) with 0
1381998420: transPiper: writing code = 203, tid = 20, count = 4
1381998420: transPiper: calling TransStop
1381998420: TransStop: send = 0, result = 540
1381998420: transPiper: transaction (20) exits
1381998420: TransStop: send = -1, result = 540
1382004926: connListener: starting thread connAccept
1382004926: connListener: Handle 2 open
1382004926: SThreadSpawn: starting thread -337695936
1382004926: Connection established by 10.0.5.230:54592
1382004926: connSetOptions: Changing TCP_NODELAY from 0 to 1
1382004926: NetSockAdd: adding socket 2 to interface 2
1382004926: connTCPConnection: conn = -188742344, code = 101, tid = 0, count = 0
1382004926: connTCPConnection: conn = -188742344, code = 158, tid = 0, count = 0
1382004926: connTCPConnection: conn = -188742344, code = 112, tid = 0, count = 4
1382004926: ConnReadData: Connection with 10.0.5.230:54592 closed
1382004926: NetSockDel: removing socket 2
1382004926: ServicePurge: service not found
1382004926: connAccept: socket 2 deleted from interface 2
1382004926: sThreadExit: exiting thread -337695936

I also find the following at the bottom of /var/log/retropds.log

1381998420: ServData: received 120 bytes of stream data
1381998420: Utf16ToMultibyte 59=>59 002f 0076 0061 0072 002f 0077 0077 0077 002f 0079 0061 006b 0069 006d 0061 0076 0061 006c 006c 0065 0079 0063 0069 0074 0079 0066 0065 0073 0074 002e 0063 006f 006d 002f 0070 0075 0062 006c 0069 0063 005f 0068 0074 006d 006c 002f 0073 0068 0061 0072 0065 0064 002f 0066 0069 006c 0065 0073 002f => 2f 76 61 72 2f 77 77 77 2f 79 61 6b 69 6d 61 76 61 6c 6c 65 79 63 69 74 79 66 65 73 74 2e 63 6f 6d 2f 70 75 62 6c 69 63 5f 68 74 6d 6c 2f 73 68 61 72 65 64 2f 66 69 6c 65 73 2f
1381998420: ServWait: received msg cpSX
1381998420: ServData: received 136 bytes of stream data
1381998420: Utf16ToMultibyte 67=>67 002f 0076 0061 0072 002f 0077 0077 0077 002f 0079 0061 006b 0069 006d 0061 0076 0061 006c 006c 0065 0079 0063 0069 0074 0079 0066 0065 0073 0074 002e 0063 006f 006d 002f 0070 0075 0062 006c 0069 0063 005f 0068 0074 006d 006c 002f 0073 0068 0061 0072 0065 0064 002f 0066 0069 006c 0065 0073 002f 0065 0078 0070 006f 0072 0074 0073 002f => 2f 76 61 72 2f 77 77 77 2f 79 61 6b 69 6d 61 76 61 6c 6c 65 79 63 69 74 79 66 65 73 74 2e 63 6f 6d 2f 70 75 62 6c 69 63 5f 68 74 6d 6c 2f 73 68 61 72 65 64 2f 66 69 6c 65 73 2f 65 78 70 6f 72 74 73 2f
1381998420: ServWait: received msg cpSX
1381998420: ServData: received 130 bytes of stream data
1381998420: Utf16ToMultibyte 64=>64 002f 0076 0061 0072 002f 0077 0077 0077 002f 0079 0061 006b 0069 006d 0061 0076 0061 006c 006c 0065 0079 0063 0069 0074 0079 0066 0065 0073 0074 002e 0063 006f 006d 002f 0070 0075 0062 006c 0069 0063 005f 0068 0074 006d 006c 002f 0073 0068 0061 0072 0065 0064 002f 0066 0069 006c 0065 0073 002f 0074 0065 0073 0074 002f => 2f 76 61 72 2f 77 77 77 2f 79 61 6b 69 6d 61 76 61 6c 6c 65 79 63 69 74 79 66 65 73 74 2e 63 6f 6d 2f 70 75 62 6c 69 63 5f 68 74 6d 6c 2f 73 68 61 72 65 64 2f 66 69 6c 65 73 2f 74 65 73 74 2f
1381998420: ServWait: received msg cpSX
1381998420: ServData: received 116 bytes of stream data
1381998420: Utf16ToMultibyte 57=>57 002f 0076 0061 0072 002f 0077 0077 0077 002f 0079 0061 006b 0069 006d 0061 0076 0061 006c 006c 0065 0079 0063 0069 0074 0079 0066 0065 0073 0074 002e 0063 006f 006d 002f 0070 0075 0062 006c 0069 0063 005f 0068 0074 006d 006c 002f 0073 0068 0061 0072 0065 0064 002f 006c 006f 0067 002f => 2f 76 61 72 2f 77 77 77 2f 79 61 6b 69 6d 61 76 61 6c 6c 65 79 63 69 74 79 66 65 73 74 2e 63 6f 6d 2f 70 75 62 6c 69 63 5f 68 74 6d 6c 2f 73 68 61 72 65 64 2f 6c 6f 67 2f
1381998420: ServWait: received msg cpSX
1381998420: ServData: received 118 bytes of stream data
1381998420: Utf16ToMultibyte 58=>58 002f 0076 0061 0072 002f 0077 0077 0077 002f 0079 0061 006b 0069 006d 0061 0076 0061 006c 006c 0065 0079 0063 0069 0074 0079 0066 0065 0073 0074 002e 0063 006f 006d 002f 0070 0075 0062 006c 0069 0063 005f 0068 0074 006d 006c 002f 0073 0068 0061 0072 0065 0064 002f 0070 0069 0064 0073 002f => 2f 76 61 72 2f 77 77 77 2f 79 61 6b 69 6d 61 76 61 6c 6c 65 79 63 69 74 79 66 65 73 74 2e 63 6f 6d 2f 70 75 62 6c 69 63 5f 68 74 6d 6c 2f 73 68 61 72 65 64 2f 70 69 64 73 2f
1381998420: ServWait: received msg cpSX
1381998420: ServData: received 122 bytes of stream data
1381998420: Utf16ToMultibyte 60=>60 002f 0076 0061 0072 002f 0077 0077 0077 002f 0079 0061 006b 0069 006d 0061 0076 0061 006c 006c 0065 0079 0063 0069 0074 0079 0066 0065 0073 0074 002e 0063 006f 006d 002f 0070 0075 0062 006c 0069 0063 005f 0068 0074 006d 006c 002f 0073 0068 0061 0072 0065 0064 002f 0073 0079 0073 0074 0065 006d 002f => 2f 76 61 72 2f 77 77 77 2f 79 61 6b 69 6d 61 76 61 6c 6c 65 79 63 69 74 79 66 65 73 74 2e 63 6f 6d 2f 70 75 62 6c 69 63 5f 68 74 6d 6c 2f 73 68 61 72 65 64 2f 73 79 73 74 65 6d 2f
1381998420: ServWait: received msg cpSX
1381998420: ServData: received 92 bytes of stream data
1381998420: Utf16ToMultibyte 45=>45 002f 0076 0061 0072 002f 0077 0077 0077 002f 0079 0061 006b 0069 006d 0061 0076 0061 006c 006c 0065 0079 0063 0069 0074 0079 0066 0065 0073 0074 002e 0063 006f 006d 002f 0073 0075 0062 0064 006f 006d 0061 0069 006e 0073 002f => 2f 76 61 72 2f 77 77 77 2f 79 61 6b 69 6d 61 76 61 6c 6c 65 79 63 69 74 79 66 65 73 74 2e 63 6f 6d 2f 73 75 62 64 6f 6d 61 69 6e 73 2f
1381998420: ServWait: received msg cpSX
1381998420: ServDone (20): result 0
1381998420: ServData: stopping transaction 20

Any insight you can provide will be appreciated.

 

  • Like 7

Share this post


Link to post
Share on other sites

Y'll are probably going to want to know version information.

 

Windows Server 7.7.762 and Linux Client 7.7.100

 

Client status says this after a failure:

$ sudo service rcl status
Server "ClientName":
        Version 7.7.100
        reserved by ServerName for Immediate Backup
        back up ASAP
        currently on
        readonly is off
        exclude is off
        1 connections, 1 authenticated
 

As it fails the server reports (automatic or manual backups don't make a difference):

"Can't reserve backup client ClientName, error -519 (network communication failed).

10/17/2013 2:48:09 AM: Execution incomplete

Total performance: 124.5MB/minute

Total duration: 04:31:33 (02:22:40 idle/loading/preparing)"

 

After failure server says "Can't acess backup client ClientName, error -505 ( backup client reserved)" until I restart the client. (This error I see on other servers also somewhat regularly, but it clears with a service restart.)

 

I've also seen the error -519 on the server with the message "Trouble reading files" and saying it can't reserve the remaining volumes after saying the one it was working on was incomplete.

  • Like 3

Share this post


Link to post
Share on other sites

When I tried to report the above, I received the following error

"Warning: Base directory HTML_PURIFIER_PATHcache/tmp does not exist, please create or change using %Cache.SerializerPath in /home/retrospe/public_html/ips_kernel/HTMLPurifier/HTMLPurifier/DefinitionCache/Serializer.php on line 133"

  • Like 1

Share this post


Link to post
Share on other sites

Create an account or sign in to comment

You need to be a member in order to leave a comment

Create an account

Sign up for a new account in our community. It's easy!

Register a new account

Sign in

Already have an account? Sign in here.

Sign In Now

×