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.
|
