Amanda-Users

Re: Amanda TCP Reset Problem with CygWin

2003-03-31 06:27:36
Subject: Re: Amanda TCP Reset Problem with CygWin
From: Enrico Bernardini <enrico AT adm.unipi DOT it>
To: Brian White <bcwhite AT precidia DOT com>
Date: Mon, 31 Mar 2003 11:34:27 +0200
Hi Brian,
use configure with --pid-debug-files if you want and
look at sendbackup.debug and runtar.debug (or something like these).
I just catched [data read: Connection reset by peer] error but I don't
remember the solution.
Send me runtar.debug please.
Did you apply my gnu tar patch?

Enrico

Brian White wrote:
> 
> Well, after several weeks of on-again, off-again work on this, I've got
> Amanda behaving pretty well under CygWin.  I've applied Enrico's patches
> for v2.4.2 to v2.4.3 and it seems to run just fine.
> 
> However, when the run completes, the CygWin amanda client completes, it
> resets the TCP connection instead of closing it properly and thus the
> server fails with the error "data read: Connection reset by peer".
> 
> Here is the tcpdump of the session.  The XP machine is "watertown" and
> the server is "tolkien".
> 
> 20:07:04.675952 tolkien.ott.precidia.com.898 > 
> watertown.ott.precidia.com.amanda:  udp 296 (DF)
> 20:07:04.917385 watertown.ott.precidia.com.amanda > 
> tolkien.ott.precidia.com.898:  udp 50
> 20:07:05.876973 watertown.ott.precidia.com.amanda > 
> tolkien.ott.precidia.com.898:  udp 85
> 20:07:05.877362 tolkien.ott.precidia.com.898 > 
> watertown.ott.precidia.com.amanda:  udp 50 (DF)
> 20:25:23.573832 tolkien.ott.precidia.com.901 > 
> watertown.ott.precidia.com.amanda:  udp 323 (DF)
> 20:25:23.808420 watertown.ott.precidia.com.amanda > 
> tolkien.ott.precidia.com.901:  udp 50
> 20:25:24.104053 watertown.ott.precidia.com.amanda > 
> tolkien.ott.precidia.com.901:  udp 232
> 20:25:24.104409 tolkien.ott.precidia.com.901 > 
> watertown.ott.precidia.com.amanda:  udp 50 (DF)
> 20:25:24.106066 tolkien.ott.precidia.com.3291 > 
> watertown.ott.precidia.com.782: S 2770461836:2770461836(0) win 5840 <mss 
> 1460,sackOK,timestamp 202856630 0,nop,wscale 0> (DF)
> 20:25:24.106719 watertown.ott.precidia.com.782 > 
> tolkien.ott.precidia.com.3291: S 1488495206:1488495206(0) ack 2770461837 win 
> 17520 <mss 1460,nop,wscale 0,nop,nop,timestamp 0 0,nop,nop,sackOK> (DF)
> 20:25:24.106821 tolkien.ott.precidia.com.3291 > 
> watertown.ott.precidia.com.782: . ack 1 win 5840 <nop,nop,timestamp 202856630 
> 0> (DF)
> 20:25:24.108097 tolkien.ott.precidia.com.3292 > 
> watertown.ott.precidia.com.783: S 2782800686:2782800686(0) win 5840 <mss 
> 1460,sackOK,timestamp 202856630 0,nop,wscale 0> (DF)
> 20:25:24.108744 watertown.ott.precidia.com.783 > 
> tolkien.ott.precidia.com.3292: S 1488548459:1488548459(0) ack 2782800687 win 
> 17520 <mss 1460,nop,wscale 0,nop,nop,timestamp 0 0,nop,nop,sackOK> (DF)
> 20:25:24.108835 tolkien.ott.precidia.com.3292 > 
> watertown.ott.precidia.com.783: . ack 1 win 5840 <nop,nop,timestamp 202856630 
> 0> (DF)
> 20:25:24.109919 tolkien.ott.precidia.com.3293 > 
> watertown.ott.precidia.com.784: S 2782309519:2782309519(0) win 5840 <mss 
> 1460,sackOK,timestamp 202856630 0,nop,wscale 0> (DF)
> 20:25:24.110570 watertown.ott.precidia.com.784 > 
> tolkien.ott.precidia.com.3293: S 1488716333:1488716333(0) ack 2782309520 win 
> 17520 <mss 1460,nop,wscale 0,nop,nop,timestamp 0 0,nop,nop,sackOK> (DF)
> 20:25:24.110672 tolkien.ott.precidia.com.3293 > 
> watertown.ott.precidia.com.784: . ack 1 win 5840 <nop,nop,timestamp 202856631 
> 0> (DF)
> 20:25:24.117646 watertown.ott.precidia.com.783 > 
> tolkien.ott.precidia.com.3292: P 1:72(71) ack 1 win 17520 <nop,nop,timestamp 
> 14177465 202856630> (DF)
> 20:25:24.117787 tolkien.ott.precidia.com.3292 > 
> watertown.ott.precidia.com.783: . ack 72 win 5840 <nop,nop,timestamp 
> 202856631 14177465> (DF)
> 20:25:24.200843 watertown.ott.precidia.com.783 > 
> tolkien.ott.precidia.com.3292: P 72:109(37) ack 1 win 17520 
> <nop,nop,timestamp 14177465 202856631> (DF)
> 20:25:24.200988 tolkien.ott.precidia.com.3292 > 
> watertown.ott.precidia.com.783: . ack 109 win 5840 <nop,nop,timestamp 
> 202856640 14177465> (DF)
> 20:25:24.201879 watertown.ott.precidia.com.783 > 
> tolkien.ott.precidia.com.3292: P 109:236(127) ack 1 win 17520 
> <nop,nop,timestamp 14177465 202856640> (DF)
> 20:25:24.201931 tolkien.ott.precidia.com.3292 > 
> watertown.ott.precidia.com.783: . ack 236 win 5840 <nop,nop,timestamp 
> 202856640 14177465> (DF)
> 20:25:24.779303 watertown.ott.precidia.com.783 > 
> tolkien.ott.precidia.com.3292: P 236:278(42) ack 1 win 17520 
> <nop,nop,timestamp 14177471 202856640> (DF)
> 20:25:24.779460 tolkien.ott.precidia.com.3292 > 
> watertown.ott.precidia.com.783: . ack 278 win 5840 <nop,nop,timestamp 
> 202856697 14177471> (DF)
> 20:25:24.975184 watertown.ott.precidia.com.784 > 
> tolkien.ott.precidia.com.3293: P 1:356(355) ack 1 win 17520 
> <nop,nop,timestamp 14177473 202856631> (DF)
> 20:25:24.975286 tolkien.ott.precidia.com.3293 > 
> watertown.ott.precidia.com.784: . ack 356 win 6432 <nop,nop,timestamp 
> 202856717 14177473> (DF)
> 20:25:25.118320 watertown.ott.precidia.com.782 > 
> tolkien.ott.precidia.com.3291: . 1:1449(1448) ack 1 win 17520 
> <nop,nop,timestamp 14177475 202856630> (DF)
> 20:25:25.119444 tolkien.ott.precidia.com.3291 > 
> watertown.ott.precidia.com.782: . ack 1449 win 8688 <nop,nop,timestamp 
> 202856731 14177475> (DF)
> 20:25:25.119382 watertown.ott.precidia.com.782 > 
> tolkien.ott.precidia.com.3291: . 1449:2897(1448) ack 1 win 17520 
> <nop,nop,timestamp 14177475 202856630> (DF)
> 20:25:25.119759 tolkien.ott.precidia.com.3291 > 
> watertown.ott.precidia.com.782: . ack 2897 win 11584 <nop,nop,timestamp 
> 202856731 14177475> (DF)
> 20:25:25.121090 watertown.ott.precidia.com.782 > 
> tolkien.ott.precidia.com.3291: P 2897:3278(381) ack 1 win 17520 
> <nop,nop,timestamp 14177475 202856731> (DF)
> 20:25:25.121190 tolkien.ott.precidia.com.3291 > 
> watertown.ott.precidia.com.782: . ack 3278 win 14480 <nop,nop,timestamp 
> 202856732 14177475> (DF)
>                                                                               
>  vvv
> 20:25:25.230050 watertown.ott.precidia.com.784 > 
> tolkien.ott.precidia.com.3293: R 1488716689:1488716689(0) win 0 (DF)
>                                                                               
>  ^^^
> 20:25:25.230284 watertown.ott.precidia.com.782 > 
> tolkien.ott.precidia.com.3291: R 1488498484:1488498484(0) win 0 (DF)
> 20:25:25.233667 tolkien.ott.precidia.com.3292 > 
> watertown.ott.precidia.com.783: F 1:1(0) ack 278 win 5840 <nop,nop,timestamp 
> 202856743 14177471> (DF)
> 20:25:25.234326 watertown.ott.precidia.com.783 > 
> tolkien.ott.precidia.com.3292: . ack 2 win 17520 <nop,nop,timestamp 14177476 
> 202856743> (DF)
> 20:25:25.264133 watertown.ott.precidia.com.783 > 
> tolkien.ott.precidia.com.3292: P 278:298(20) ack 2 win 17520 
> <nop,nop,timestamp 14177476 202856743> (DF)
> 20:25:25.264297 tolkien.ott.precidia.com.3292 > 
> watertown.ott.precidia.com.783: R 2782800688:2782800688(0) win 0 (DF)
> 
> On watertown, the "sendbackup" log in /tmp/amanda shows:
> 
> sendbackup: debug 1 pid 2736 ruid 0 euid 0: start at Thu Mar 27 20:24:45 2003
> /usr/local/lib/amanda/sendbackup: version 2.4.3
>   parsed request as: program `GNUTAR'
>                      disk `/home/watertown'
>                      device `/home/watertown'
>                      level 0
>                      since 1970:1:1:0:0:0
>                      options 
> `|;bsd-auth;compress-fast;index;exclude-file=^(#|Backup.of)|.(bak|tmp|fla|fst|hex|lib|lst|m
> 51|wav|mp3|mpg|mpeg|avi|mov|obj|omf|prn|swp)$|~$;'
> sendbackup: try_socksize: send buffer size is 65536
> sendbackup: time 0.014: stream_server: waiting for connection: 0.0.0.0.782
> sendbackup: time 0.016: stream_server: waiting for connection: 0.0.0.0.783
> sendbackup: time 0.016: stream_server: waiting for connection: 0.0.0.0.784
> sendbackup: time 0.018: waiting for connect on 782, then 783, then 784
> sendbackup: time 0.031: stream_accept: connection from 10.0.1.2.3291
> sendbackup: time 0.033: stream_accept: connection from 10.0.1.2.3292
> sendbackup: time 0.035: stream_accept: connection from 10.0.1.2.3293
> sendbackup: time 0.035: got all connections
> sendbackup: time 0.036: spawning /usr/bin/gzip in pipeline
> sendbackup: argument list: /usr/bin/gzip --fast
> sendbackup-gnutar: time 0.086: pid 2524: /usr/bin/gzip --fast
> sendbackup-gnutar: time 0.090: doing level 0 dump as listed-incremental to 
> /var/lib/amanda/gnutar-lists/watertown.ott.pr
> ecidia.com_home_watertown_0.new
> sendbackup-gnutar: time 0.105: doing level 0 dump from date: 1970-01-01  
> 0:00:00 GMT
> sendbackup: time 0.217: spawning /usr/local/lib/amanda/runtar in pipeline
> sendbackup: argument list: gtar --create --file - --directory /home/watertown 
> --listed-incremental /var/lib/amanda/gnuta
> r-lists/watertown.ott.precidia.com_home_watertown_0.new --sparse 
> --ignore-failed-read --totals --exclude-from /tmp/amand
> a/sendbackup._home_watertown.20030327202446.exclude .
> sendbackup-gnutar: time 0.292: /usr/local/lib/amanda/runtar: pid 1796
> sendbackup: time 0.311: started index creator: "/usr/bin/tar -tf - 
> 2>/dev/null | sed -e 's/^\.//'"
> sendbackup: time 0.697:  53:    size(|): Total bytes written: 20480 (20kB, 
> ?B/s)
> sendbackup: time 1.024: index created successfully
> sendbackup: time 1.293: pid 2736 finish time Thu Mar 27 20:24:47 2003
> 
> and the "amandad" log shows:
> 
> amandad: debug 1 pid 612 ruid 0 euid 0: start at Thu Mar 27 20:24:45 2003
> amandad: version 2.4.3
> amandad: build: VERSION="Amanda-2.4.3"
> amandad:        BUILT_DATE="Tue Mar 11 17:36:38 EST 2003"
> amandad:        BUILT_MACH="CYGWIN_NT-5.1 watertown 1.3.20(0.73/3/2) 
> 2003-02-08 12:10 i686 unknown unknown Cygwin"
> amandad:        CC="gcc"
> amandad:        CONFIGURE_COMMAND="'./configure' '--without-server' 
> '--without-restore' '--without-force-uid' '--with-us
> er=root' '--with-group=root' '--libdir=/usr/local/lib/amanda' 
> '--libexecdir=/usr/local/lib/amanda' '--localstatedir=/var
> /lib' '--sysconfdir=/etc'"
> amandad: paths: bindir="/usr/local/bin" sbindir="/usr/local/sbin"
> amandad:        libexecdir="/usr/local/lib/amanda" mandir="/usr/local/man"
> amandad:        AMANDA_TMPDIR="/tmp/amanda" AMANDA_DBGDIR="/tmp/amanda"
> amandad:        CONFIG_DIR="/etc/amanda" DEV_PREFIX="/" RDEV_PREFIX="/"
> amandad:        GNUTAR="/usr/bin/tar" COMPRESS_PATH="/usr/bin/gzip"
> amandad:        UNCOMPRESS_PATH="/usr/bin/gzip" MAILER="NONE"
> amandad:        listed_incr_dir="/var/lib/amanda/gnutar-lists"
> amandad: defs:  DEFAULT_SERVER="watertown" DEFAULT_CONFIG="DailySet1"
> amandad:        DEFAULT_TAPE_SERVER="watertown"
> amandad:        DEFAULT_TAPE_DEVICE="/dev/null" LOCKING=POSIX_FCNTL
> amandad:        SETPGRP_VOID DEBUG_CODE AMANDA_DEBUG_DAYS=4 BSD_SECURITY
> amandad:        USE_AMANDAHOSTS CLIENT_LOGIN="root" HAVE_GZIP
> amandad:        COMPRESS_SUFFIX=".gz" COMPRESS_FAST_OPT="--fast"
> amandad:        COMPRESS_BEST_OPT="--best" UNCOMPRESS_OPT="-dc"
> amandad: time 0.006: got packet:
> --------
> Amanda 2.4 REQ HANDLE 000-D0D60608 SEQ 1048813622
> SECURITY USER backup
> SERVICE sendbackup
> OPTIONS hostname=watertown.ott.precidia.com;
> GNUTAR /home/watertown 0 1970:1:1:0:0:0 OPTIONS 
> |;bsd-auth;compress-fast;index;exclude-file=^(#|Backup.of)|.(bak|tmp|fla
> |fst|hex|lib|lst|m51|wav|mp3|mpg|mpeg|avi|mov|obj|omf|prn|swp)$|~$;
> --------
> 
> amandad: time 0.007: sending ack:
> ----
> Amanda 2.4 ACK HANDLE 000-D0D60608 SEQ 1048813622
> ----
> 
> amandad: time 0.017: bsd security: remote host tolkien.ott.precidia.com user 
> backup local user root
> amandad: time 0.018: amandahosts security check passed
> amandad: time 0.018: running service "/usr/local/lib/amanda/sendbackup"
> amandad: time 0.301: sending REP packet:
> ----
> Amanda 2.4 REP HANDLE 000-D0D60608 SEQ 1048813622
> CONNECT DATA 782 MESG 783 INDEX 784
> OPTIONS 
> compress-fast;bsd-auth;index;exclude-file=^(#|Backup.of)|.(bak|tmp|fla|fst|hex|lib|lst|m51|wav|mp3|mpg|mpeg|avi|
> mov|obj|omf|prn|swp)$|~$;
> ----
> 
> amandad: time 0.304: got packet:
> ----
> Amanda 2.4 ACK HANDLE 000-D0D60608 SEQ 1048813622
> ----
> 
> amandad: time 0.304: pid 612 finish time Thu Mar 27 20:24:46 2003
> 
> On the server, I could find no mention of "watertown" or its IP address
> anywhere in the log files, but here's what it said in the mail report:
> 
> /-- watertown. /home/watertown lev 0 FAILED [data read: Connection reset by 
> peer]
> sendbackup: start [watertown.ott.precidia.com:/home/watertown level 0]
> sendbackup: info BACKUP=/usr/bin/tar
> sendbackup: info RECOVER_CMD=/usr/bin/gzip -dc |/usr/bin/tar -f... -
> sendbackup: info COMPRESS_SUFFIX=.gz
> sendbackup: info end
> | Total bytes written: 20480 (20kB, ?B/s)
> \--------
> 
> Any ideas on why the transfer is ending with a RST instead of a FIN?
> 
>                                           Brian
>                                  ( bcwhite AT precidia DOT com )
> 
> -------------------------------------------------------------------------------
>  ... was no trading on the NYSE today; everybody was happy with what they had.

-- 

Dr. Enrico Bernardini
System Administrator

Servizio Sistema Bibliotecario
Universita' di Pisa

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