Amanda-Users

Re: connection problem during `sendbackup' stage

2008-09-10 08:49:26
Subject: Re: connection problem during `sendbackup' stage
From: Jukka Salmi <j+amanda AT 2008.salmi DOT ch>
To: amanda-users AT amanda DOT org
Date: Wed, 10 Sep 2008 14:40:29 +0200
Dustin J. Mitchell --> amanda-users (2008-09-09 09:58:15 -0400):
> On Tue, Sep 9, 2008 at 8:50 AM, Jukka Salmi <j+amanda AT 2008.salmi DOT ch> 
> wrote:
> > c:10080 -> s:846 udp Amanda 2.5 REP HANDLE ... CONNECT DATA 56639 MESG 
> > 56638 INDEX 56637 ...
> > s:846 -> c:10080 udp Amanda 2.4 ACK HANDLE ...
> >
> > s:50029 -> c:56639 tcp SYN
> > c:56639 -> s:50029 tcp SYN,RST
> >
> > Oops. IIUC this TCP connection is supposd to transfer the actual data
> > to back up. Hmm, why could it be reset by the client?
> 
> Most likely, the port is closed by the time the server tries to
> contact it, because something has gone wrong on the client.  Note that
> the index tee uses 'sed'.  Is that sed invocation failing on NetBSD?
> Check the sendbackup debug logs.

Hmm, sed seems not to be the problem here AFAICT.

Some of the sendbackup logs on the client look ok:

[...]
sendbackup: time 0.002: spawning /usr/pkg/libexec/runtar in pipeline
sendbackup: time 0.002: argument list: runtar NOCONFIG gtar --create [...]
sendbackup-gnutar: time 0.002: /usr/pkg/libexec/runtar: pid 4766
sendbackup: time 0.002: started backup
sendbackup: time 0.008: started index creator: "/usr/pkg/bin/gtar -tf - 
2>/dev/null | sed -e 's/^\.//'"
sendbackup: time 0.015:  47:    size(|): Total bytes written: 10240 (10KiB, 
33MiB/s)
sendbackup: time 0.017: index created successfully
sendbackup: time 0.017: parsed backup messages
sendbackup: time 0.017: pid 10092 finish time Tue Sep  9 17:32:15 2008

while some don't:

[...]
sendbackup: time 0.002: spawning /usr/pkg/libexec/runtar in pipeline
sendbackup: time 0.002: argument list: runtar NOCONFIG gtar --create [...]
sendbackup-gnutar: time 0.002: /usr/pkg/libexec/runtar: pid 21997
sendbackup: time 0.002: started backup
sendbackup: time 0.004: started index creator: "/usr/pkg/bin/gtar -tf - 
2>/dev/null | sed -e 's/^\.//'"
sendbackup: time 195.078: index tee cannot write [Broken pipe]
sendbackup: time 195.078: pid 4821 finish time Tue Sep  9 17:35:30 2008

The amandad log reveals:

[...]
SERVICE sendbackup
[...]
CONNECT DATA 65311 MESG 65310 INDEX 65309
OPTIONS features=ffffffff9ffeffffffff00;
>>>>>
amandad: time 30.206: dgram_send_addr(addr=0x8056120, dgram=0xbbba3e04)
amandad: time 30.206: (sockaddr_in *)0x8056120 = { 2, 844, 192.168.12.15 }
amandad: time 30.206: dgram_send_addr: 0xbbba3e04->socket = 0
amandad: time 30.207: dgram_recv(dgram=0xbbba3e04, timeout=0, 
fromaddr=0xbbbb3df0)
amandad: time 30.207: (sockaddr_in *)0xbbbb3df0 = { 2, 844, 192.168.12.15 }
amandad: time 30.207: received ACK pkt:
<<<<<
>>>>>
amandad: time 30.214: stream_accept: select() failed: Interrupted system call
amandad: time 60.247: stream_accept: timeout after 30 seconds
amandad: time 60.247: security_stream_seterr(0x8076000, can't accept new stream 
connection: No such file or directory)
amandad: time 60.247: stream 0 accept failed: unknown protocol error
amandad: time 60.247: security_stream_close(0x8076000)
amandad: time 90.310: stream_accept: timeout after 30 seconds
amandad: time 90.311: security_stream_seterr(0x807f000, can't accept new stream 
connection: No such file or directory)
amandad: time 90.311: stream 1 accept failed: unknown protocol error
amandad: time 90.311: security_stream_close(0x807f000)
amandad: time 120.387: stream_accept: timeout after 30 seconds
amandad: time 120.387: security_stream_seterr(0x8088000, can't accept new 
stream connection: No such file or directory)
amandad: time 120.387: stream 2 accept failed: unknown protocol error
amandad: time 120.387: security_stream_close(0x8088000)
amandad: time 120.387: security_close(handle=0x8056100, driver=0xbbba1f20 (BSD))
amandad: time 120.387: pid 14131 finish time Tue Sep  9 17:28:59 2008

Hmm, EINTR. I'll try to reproduce this with another version of NetBSD
(trying with 4.0_STABLE ATM) before debugging any further...

Any hints?

TIA, Jukka

-- 
bashian roulette:
$ ((RANDOM%6)) || rm -rf ~

<Prev in Thread] Current Thread [Next in Thread>