rsync - Oct 2003 - error in rsync protocol data stream (code 12) at io.c

List,

I am having trouble with a previously working rsync server.

Version:
> # rsync --version
> rsync  version 2.5.4  protocol version 26
> Copyright (C) 1996-2002 by Andrew Tridgell and others
> <http://rsync.samba.org/>
> Capabilities: 64-bit files, socketpairs, hard links, symlinks, 
> batchfiles, IPv6,              64-bit system inums, 64-bit internal inums
rsyncd.conf :

# RSYNCD Configuration
 
[vice]
        path = /vader1/admin/backup/vice/
        comment = vice msqldb backup
        hosts allow = 'ip address of vice'
        uid = 0
        gid = 0
        max connections = 30
        use chroot = yes
        read only = no

Rsync is running and I can connect to it with netcat from the server 
vice.  It shows the port is open.  On vader which is the rsync server, 
the disk is not full.

/dev/sdb1            352153072 124431844 209832856  38% /vader1

I had been running a script to rsync over a bunch of stuff but now its 
giving me this error:

[root@vice admin]# rsync -avz mysql.sql vader::vice
rsync: connection unexpectedly closed (0 bytes read so far)
rsync error: error in rsync protocol data stream (code 12) at io.c(150)

I have been reading the posts and havent found an answer yet.  Your help 
is greatly appreciated.

Thanks,

-- 
Jonathan W. Sabo
Code 5580
Naval Research Lab
sabo@ait.nrl.navy.mil
Fax: (202)-404-1190 
Phone: (202)-767-3901

On Mon, Oct 06, 2003 at 11:42:00AM -0400, jonathan sabo
wrote:
> List,
> 
> I am having trouble with a previously working rsync server.
> 
> Version:
> 
> ># rsync --version
> >rsync  version 2.5.4  protocol version 26
> >Copyright (C) 1996-2002 by Andrew Tridgell and others
> ><http://rsync.samba.org/>
> >Capabilities: 64-bit files, socketpairs, hard links, symlinks, 
> >batchfiles, IPv6,              64-bit system inums, 64-bit internal
inums
While 2.5.4 was obsoleted about 17 months ago this is
unlikely to be a bug.
> Rsync is running and I can connect to it with netcat from the server 
> vice.  It shows the port is open.  On vader which is the rsync server, 
> the disk is not full.
> 
> /dev/sdb1            352153072 124431844 209832856  38% /vader1
> 
> I had been running a script to rsync over a bunch of stuff but now its 
> giving me this error:
> 
> [root@vice admin]# rsync -avz mysql.sql vader::vice
> rsync: connection unexpectedly closed (0 bytes read so far)
> rsync error: error in rsync protocol data stream (code 12) at io.c(150)
> 
> I have been reading the posts and havent found an answer yet.  Your help 
> is greatly appreciated.
Apparently you didn't read the archives.

Start by examining what might have changed.  Look at the
logs on vader.  Then increment the verbosity at the client.
If no other error messages turn up it is probably a firewall
dropping the session.

-- 
________________________________________________________________
	J.W. Schultz            Pegasystems Technologies
	email address:		jw@pegasys.ws

		Remember Cernan and Schmitt

I DID read the archives and from them figured that I would receive a very
helpful responce from you Mr. Schultz.  Thanks for your attention.  The
recomendation to turn up verbosity on the client did not help.  I still only
know that I can connect and then I get an error as shown below:

[root@vice admin]# rsync -avvvvz mysql.sql vader::vice
opening tcp connection to vader port 873
rsync: connection unexpectedly closed (0 bytes read so far)
_exit_cleanup(code=12, file=io.c, line=165): entered
rsync error: error in rsync protocol data stream (code 12) at io.c(165)
_exit_cleanup(code=12, file=io.c, line=165): about to call exit(12)
[root@vice admin]#

Nothing that I can think of has changed on either the server or clients
but obviously something must have because it was working in the past.  I
updated rsync, so it is no longer 17 months outdated:
>>> (09:01pm) (root@vader) (0/pts/0) (~)
# rsync --version
rsync  version 2.5.6  protocol version 26
Copyright (C) 1996-2002 by Andrew Tridgell and others
<http://rsync.samba.org/>
Capabilities: 64-bit files, socketpairs, hard links, symlinks, batchfiles,
              IPv6, 64-bit system inums, 64-bit internal inums

rsync comes with ABSOLUTELY NO WARRANTY.  This is free software, and you
are welcome to redistribute it under certain conditions.  See the GNU
General Public Licence for details.

One thing I have noticed while troubleshooting is that other rsync servers
with the same configuration, ie. same rsyncd.conf and xinetd.d/rsync
config respond differently to netcat as shown below:

Working Rsync server:

[root@vice admin]# nc -vvv excelsior 873
excelsior.ait.nrl.navy.mil [132.250.128.31] 873 (rsync) open
@RSYNCD: 26

@ERROR: protocol startup error
sent 1, rcvd 43

Not Working (vader):

[root@vice admin]# nc -vvv vader 873
vader.ait.nrl.navy.mil [132.250.129.162] 873 (rsync) open

sent 2, rcvd 0

So it does look like a network problem.  I have disabled both firewalls on
each machine, even though they shouldn't be affecting this and I still get
the same thing.  I have moved the /etc/hosts.allow files out of the way
along with /etc/hosts.deny.

Running tcpdump on vader while I try to rsync from vice shows the packets
are getting there:
>>> (09:16pm) (root@vader) (0/pts/0) (~)
# tcpdump -i eth0 | grep vice
tcpdump: listening on eth0
21:17:44.973404 vice.48443 > vader.rsync: S
4014526995:4014526995(0) win 5840 <mss 1460,sackOK,timestamp 29518207
0,nop,wscale 0> (DF)
21:17:44.973471 vader.rsync > vice.48443: S
668679285:668679285(0) ack 4014526996 win 5792 <mss 1460,sackOK,timestamp
6919728 29518207,nop,wscale 2> (DF)
21:17:44.973614 vice.48443 > vader.rsync: . ack 1 win
5840 <nop,nop,timestamp 29518207 6919728> (DF)
21:17:44.973678 vice.48443 > vader.rsync: P 1:13(12) ack
1 win
5840 <nop,nop,timestamp 29518207 6919728> (DF)
21:17:44.973708 vader.rsync > vice.48443: . ack 13 win
1448 <nop,nop,timestamp 6919728 29518207> (DF)
21:17:44.973957 vader.rsync > vice.48443: F 1:1(0) ack 13
win 1448 <nop,nop,timestamp 6919728 29518207> (DF)
21:17:44.974387 vice.48443 > vader.rsync: F 13:13(0) ack
2 win
5840 <nop,nop,timestamp 29518208 6919728> (DF)
21:17:44.974413 vader.rsync > vice.48443: . ack 14 win
1448 <nop,nop,timestamp 6919728 29518208> (DF)

So I dont think it is a network problem, the packets from vice are being
sent correctly and are being received.  The rsync server on vader does not
respond correctly.   Do you have any ideas on what else I can change or
test?

Thanks,

Jonathan Sabo
Code 5580
NRL