Troubleshooting rsync

Previous Topic Next Topic
 
classic Classic list List threaded Threaded
5 messages Options
Reply | Threaded
Open this post in threaded view
|

Troubleshooting rsync

Greg Thomas-2
Hey all, I'm trying to use WSL on Windows 10 to backup to my OpenBSD server
running 6.7 release.  It looks like Debian on WSL is using rsync version
3.1.2.  I tried both the rsync package and openrsync on OpenBSD with the
same results.    Basically rsync never exits and when I use four Vs for
verbosity the last line is 'client_run waiting on..."   rsync locally works
fine.

I'm not sure how to go about troubleshooting this further.  Any suggestions
would be appreciated.

ethant@NIHILANON:/mnt/c/Users/ethant$ rsync -rvvvv
--rsync-path=/usr/bin/openrsync -e /mnt/c/Windows/System32/OpenSSH/ss
h.exe /mnt/c/Users/ethant/Downloads ethant@192.168.0.61:/home/ethant/
cmd=/mnt/c/Windows/System32/OpenSSH/ssh.exe machine=192.168.0.61
user=ethant path=/home/ethant/
cmd[0]=/mnt/c/Windows/System32/OpenSSH/ssh.exe cmd[1]=-l cmd[2]=ethant
cmd[3]=192.168.0.61 cmd[4]=/usr/bin/openrsync cmd[5]=--server
cmd[6]=-vvvvre.iLsfxC cmd[7]=. cmd[8]=/home/ethant/
opening connection using: /mnt/c/Windows/System32/OpenSSH/ssh.exe -l ethant
192.168.0.61 /usr/bin/openrsync --server -vvvvre.iLsfxC . /home/ethant/  (9
args)
msg checking charset: UTF-8
(Client) Protocol versions: remote=27, negotiated=27
/usr/src/usr.bin/rsync/server.c:99: server detected client version 31,
server version 27, seed -1979080380
building file list ... /usr/src/usr.bin/rsync/server.c:128: server starting
receiver

[sender] make_file(Downloads,*,0)
[sender] pushing local filters for /mnt/c/Users/ethant/Downloads/
[sender] make_file(Downloads/desktop.ini,*,2)
[sender] popping local filters
done
[sender] flist start=0, used=2, low=0, high=1
[sender] i=0 /mnt/c/Users/ethant Downloads/ mode=040777 len=512 flags=5
[sender] i=1 /mnt/c/Users/ethant Downloads/desktop.ini mode=0100777 len=282
flags=0
send_file_list done
[sender] flist_eof=1
file list sent
send_files starting
/usr/src/usr.bin/rsync/flist.c:739: Downloads: received file metadata: size
512, mtime 1599280175, mode 40777, rdev (0, 0)
/usr/src/usr.bin/rsync/flist.c:739: Downloads/desktop.ini: received file
metadata: size 282, mtime 1599125537, mode 100777, rdev (0, 0)
/usr/src/usr.bin/rsync/flist.c:765: received file metadata list: 2
/usr/src/usr.bin/rsync/flist.c:169: Downloads: top-level
/usr/src/usr.bin/rsync/receiver.c:233: /home/ethant/: receiver destination
/usr/src/usr.bin/rsync/receiver.c:329: /home/ethant/: ready for phase 1 data
/usr/src/usr.bin/rsync/uploader.c:544: Downloads: updating directory
/usr/src/usr.bin/rsync/uploader.c:949: i=0, offs=700, msz=282, blk.len=700,
blk.rem=282
send_files(1, /mnt/c/Users/ethant/Downloads/desktop.ini)
/usr/src/usr.bin/rsync/uploader.c:957: Downloads/desktop.ini: mapped 282 B
with 1 blocks
/usr/src/usr.bin/rsync/uploader.c:848: uploader: finished
count=1 n=700 rem=282
chunk[0] len=282 offset=0 sum1=d0fa3006
send_files mapped /mnt/c/Users/ethant/Downloads/desktop.ini of size 282
calling match_sums /mnt/c/Users/ethant/Downloads/desktop.ini
Downloads/desktop.ini
built hash table
hash search b=700 len=282
sum=d0fa3006 k=282
hash search s->blength=700 len=282 count=1
potential match at 0 i=0 sum=d0fa3006
match at 0 last_match=0 j=0 len=282 n=0
done hash search
sending file_sum
false_alarms=0 hash_hits=1 matches=1
sender finished /mnt/c/Users/ethant/Downloads/desktop.ini
send_files phase=1
/usr/src/usr.bin/rsync/downloader.c:435: Downloads/desktop.ini: temporary:
Downloads/.desktop.ini.M0XjFWs8af
/usr/src/usr.bin/rsync/downloader.c:514: Downloads/.desktop.ini.M0XjFWs8af:
copied 282 B
/usr/src/usr.bin/rsync/receiver.c:99: Downloads/desktop.ini: updated
permissions
send files finished
/usr/src/usr.bin/rsync/downloader.c:321: downloader: phase complete
/usr/src/usr.bin/rsync/receiver.c:404: /home/ethant/: receiver ready for
phase 2 data
total: matches=1  hash_hits=1  false_alarms=0 data=0
/usr/src/usr.bin/rsync/receiver.c:453: receiver finished updating
client_run waiting on 3218
Reply | Threaded
Open this post in threaded view
|

Re: Troubleshooting rsync

Predrag Punosevac-2
Greg Thomas <get.misc.openbsd () gmail ! com> wrote:

> Hey all, I'm trying to use WSL on Windows 10 to backup to my OpenBSD server
> running 6.7 release.  It looks like Debian on WSL is using rsync version
> 3.1.2.  I tried both the rsync package and openrsync on OpenBSD with the
> same results.    Basically rsync never exits and when I use four Vs for
> verbosity the last line is 'client_run waiting on..."   rsync locally works
> fine.
>
> I'm not sure how to go about troubleshooting this further.  Any suggestions
> would be appreciated.
>

Could you please show the output of the command syspatch -l ?  Could you
please confirm that you are doing rsync over ssh rather than using rsync
own protocol?

Based upon what I see this might be actually LibreSSL bug similar to the
one previously reported by me

https://marc.info/?l=openbsd-misc&m=159718134822470&w=2

It looks like SSL session is just not closing. Did rsync actually
transfer data?

Best,
Predrag


> ethant@NIHILANON:/mnt/c/Users/ethant$ rsync -rvvvv
> --rsync-path=/usr/bin/openrsync -e /mnt/c/Windows/System32/OpenSSH/ss
> h.exe /mnt/c/Users/ethant/Downloads ethant@192.168.0.61:/home/ethant/
> cmd=/mnt/c/Windows/System32/OpenSSH/ssh.exe machine=192.168.0.61
> user=ethant path=/home/ethant/
> cmd[0]=/mnt/c/Windows/System32/OpenSSH/ssh.exe cmd[1]=-l cmd[2]=ethant
> cmd[3]=192.168.0.61 cmd[4]=/usr/bin/openrsync cmd[5]=--server
> cmd[6]=-vvvvre.iLsfxC cmd[7]=. cmd[8]=/home/ethant/
> opening connection using: /mnt/c/Windows/System32/OpenSSH/ssh.exe -l ethant
> 192.168.0.61 /usr/bin/openrsync --server -vvvvre.iLsfxC . /home/ethant/  (9
> args)
> msg checking charset: UTF-8
> (Client) Protocol versions: remote=27, negotiated=27
> /usr/src/usr.bin/rsync/server.c:99: server detected client version 31,
> server version 27, seed -1979080380
> building file list ... /usr/src/usr.bin/rsync/server.c:128: server starting
> receiver
>
> [sender] make_file(Downloads,*,0)
> [sender] pushing local filters for /mnt/c/Users/ethant/Downloads/
> [sender] make_file(Downloads/desktop.ini,*,2)
> [sender] popping local filters
> done
> [sender] flist start=0, used=2, low=0, high=1
> [sender] i=0 /mnt/c/Users/ethant Downloads/ mode=040777 len=512 flags=5
> [sender] i=1 /mnt/c/Users/ethant Downloads/desktop.ini mode=0100777 len=282
> flags=0
> send_file_list done
> [sender] flist_eof=1
> file list sent
> send_files starting
> /usr/src/usr.bin/rsync/flist.c:739: Downloads: received file metadata: size
> 512, mtime 1599280175, mode 40777, rdev (0, 0)
> /usr/src/usr.bin/rsync/flist.c:739: Downloads/desktop.ini: received file
> metadata: size 282, mtime 1599125537, mode 100777, rdev (0, 0)
> /usr/src/usr.bin/rsync/flist.c:765: received file metadata list: 2
> /usr/src/usr.bin/rsync/flist.c:169: Downloads: top-level
> /usr/src/usr.bin/rsync/receiver.c:233: /home/ethant/: receiver destination
> /usr/src/usr.bin/rsync/receiver.c:329: /home/ethant/: ready for phase 1 data
> /usr/src/usr.bin/rsync/uploader.c:544: Downloads: updating directory
> /usr/src/usr.bin/rsync/uploader.c:949: i=0, offs=700, msz=282, blk.len=700,
> blk.rem=282
> send_files(1, /mnt/c/Users/ethant/Downloads/desktop.ini)
> /usr/src/usr.bin/rsync/uploader.c:957: Downloads/desktop.ini: mapped 282 B
> with 1 blocks
> /usr/src/usr.bin/rsync/uploader.c:848: uploader: finished
> count=1 n=700 rem=282
> chunk[0] len=282 offset=0 sum1=d0fa3006
> send_files mapped /mnt/c/Users/ethant/Downloads/desktop.ini of size 282
> calling match_sums /mnt/c/Users/ethant/Downloads/desktop.ini
> Downloads/desktop.ini
> built hash table
> hash search b=700 len=282
> sum=d0fa3006 k=282
> hash search s->blength=700 len=282 count=1
> potential match at 0 i=0 sum=d0fa3006
> match at 0 last_match=0 j=0 len=282 n=0
> done hash search
> sending file_sum
> false_alarms=0 hash_hits=1 matches=1
> sender finished /mnt/c/Users/ethant/Downloads/desktop.ini
> send_files phase=1
> /usr/src/usr.bin/rsync/downloader.c:435: Downloads/desktop.ini: temporary:
> Downloads/.desktop.ini.M0XjFWs8af
> /usr/src/usr.bin/rsync/downloader.c:514: Downloads/.desktop.ini.M0XjFWs8af:
> copied 282 B
> /usr/src/usr.bin/rsync/receiver.c:99: Downloads/desktop.ini: updated
> permissions
> send files finished
> /usr/src/usr.bin/rsync/downloader.c:321: downloader: phase complete
> /usr/src/usr.bin/rsync/receiver.c:404: /home/ethant/: receiver ready for
> phase 2 data
> total: matches=1  hash_hits=1  false_alarms=0 data=0
> /usr/src/usr.bin/rsync/receiver.c:453: receiver finished updating
> client_run waiting on 3218

Reply | Threaded
Open this post in threaded view
|

Re: Troubleshooting rsync

Greg Thomas-2
Thanks for reading this.  This server hasn't been patched yet, so if I
understand correctly the lack of output of syspatch -l that I get is
because I haven't patched anything yet.

Yes, I'm using it over SSH.

From checking a couple of directories that I added to my backup script it
looks like everything transfers.  I wait until I see " client_run waiting
on", hit ctrl C, and the script moves on.

On Sat, Sep 5, 2020 at 8:55 PM Predrag Punosevac <[hidden email]>
wrote:

> Greg Thomas <get.misc.openbsd () gmail ! com> wrote:
>
> > Hey all, I'm trying to use WSL on Windows 10 to backup to my OpenBSD
> server
> > running 6.7 release.  It looks like Debian on WSL is using rsync version
> > 3.1.2.  I tried both the rsync package and openrsync on OpenBSD with the
> > same results.    Basically rsync never exits and when I use four Vs for
> > verbosity the last line is 'client_run waiting on..."   rsync locally
> works
> > fine.
> >
> > I'm not sure how to go about troubleshooting this further.  Any
> suggestions
> > would be appreciated.
> >
>
> Could you please show the output of the command syspatch -l ?  Could you
> please confirm that you are doing rsync over ssh rather than using rsync
> own protocol?
>
> Based upon what I see this might be actually LibreSSL bug similar to the
> one previously reported by me
>
> https://marc.info/?l=openbsd-misc&m=159718134822470&w=2
>
> It looks like SSL session is just not closing. Did rsync actually
> transfer data?
>
> Best,
> Predrag
>
>
> > ethant@NIHILANON:/mnt/c/Users/ethant$ rsync -rvvvv
> > --rsync-path=/usr/bin/openrsync -e /mnt/c/Windows/System32/OpenSSH/ss
> > h.exe /mnt/c/Users/ethant/Downloads ethant@192.168.0.61:/home/ethant/
> > cmd=/mnt/c/Windows/System32/OpenSSH/ssh.exe machine=192.168.0.61
> > user=ethant path=/home/ethant/
> > cmd[0]=/mnt/c/Windows/System32/OpenSSH/ssh.exe cmd[1]=-l cmd[2]=ethant
> > cmd[3]=192.168.0.61 cmd[4]=/usr/bin/openrsync cmd[5]=--server
> > cmd[6]=-vvvvre.iLsfxC cmd[7]=. cmd[8]=/home/ethant/
> > opening connection using: /mnt/c/Windows/System32/OpenSSH/ssh.exe -l
> ethant
> > 192.168.0.61 /usr/bin/openrsync --server -vvvvre.iLsfxC . /home/ethant/
> (9
> > args)
> > msg checking charset: UTF-8
> > (Client) Protocol versions: remote=27, negotiated=27
> > /usr/src/usr.bin/rsync/server.c:99: server detected client version 31,
> > server version 27, seed -1979080380
> > building file list ... /usr/src/usr.bin/rsync/server.c:128: server
> starting
> > receiver
> >
> > [sender] make_file(Downloads,*,0)
> > [sender] pushing local filters for /mnt/c/Users/ethant/Downloads/
> > [sender] make_file(Downloads/desktop.ini,*,2)
> > [sender] popping local filters
> > done
> > [sender] flist start=0, used=2, low=0, high=1
> > [sender] i=0 /mnt/c/Users/ethant Downloads/ mode=040777 len=512 flags=5
> > [sender] i=1 /mnt/c/Users/ethant Downloads/desktop.ini mode=0100777
> len=282
> > flags=0
> > send_file_list done
> > [sender] flist_eof=1
> > file list sent
> > send_files starting
> > /usr/src/usr.bin/rsync/flist.c:739: Downloads: received file metadata:
> size
> > 512, mtime 1599280175, mode 40777, rdev (0, 0)
> > /usr/src/usr.bin/rsync/flist.c:739: Downloads/desktop.ini: received file
> > metadata: size 282, mtime 1599125537, mode 100777, rdev (0, 0)
> > /usr/src/usr.bin/rsync/flist.c:765: received file metadata list: 2
> > /usr/src/usr.bin/rsync/flist.c:169: Downloads: top-level
> > /usr/src/usr.bin/rsync/receiver.c:233: /home/ethant/: receiver
> destination
> > /usr/src/usr.bin/rsync/receiver.c:329: /home/ethant/: ready for phase 1
> data
> > /usr/src/usr.bin/rsync/uploader.c:544: Downloads: updating directory
> > /usr/src/usr.bin/rsync/uploader.c:949: i=0, offs=700, msz=282,
> blk.len=700,
> > blk.rem=282
> > send_files(1, /mnt/c/Users/ethant/Downloads/desktop.ini)
> > /usr/src/usr.bin/rsync/uploader.c:957: Downloads/desktop.ini: mapped 282
> B
> > with 1 blocks
> > /usr/src/usr.bin/rsync/uploader.c:848: uploader: finished
> > count=1 n=700 rem=282
> > chunk[0] len=282 offset=0 sum1=d0fa3006
> > send_files mapped /mnt/c/Users/ethant/Downloads/desktop.ini of size 282
> > calling match_sums /mnt/c/Users/ethant/Downloads/desktop.ini
> > Downloads/desktop.ini
> > built hash table
> > hash search b=700 len=282
> > sum=d0fa3006 k=282
> > hash search s->blength=700 len=282 count=1
> > potential match at 0 i=0 sum=d0fa3006
> > match at 0 last_match=0 j=0 len=282 n=0
> > done hash search
> > sending file_sum
> > false_alarms=0 hash_hits=1 matches=1
> > sender finished /mnt/c/Users/ethant/Downloads/desktop.ini
> > send_files phase=1
> > /usr/src/usr.bin/rsync/downloader.c:435: Downloads/desktop.ini:
> temporary:
> > Downloads/.desktop.ini.M0XjFWs8af
> > /usr/src/usr.bin/rsync/downloader.c:514:
> Downloads/.desktop.ini.M0XjFWs8af:
> > copied 282 B
> > /usr/src/usr.bin/rsync/receiver.c:99: Downloads/desktop.ini: updated
> > permissions
> > send files finished
> > /usr/src/usr.bin/rsync/downloader.c:321: downloader: phase complete
> > /usr/src/usr.bin/rsync/receiver.c:404: /home/ethant/: receiver ready for
> > phase 2 data
> > total: matches=1  hash_hits=1  false_alarms=0 data=0
> > /usr/src/usr.bin/rsync/receiver.c:453: receiver finished updating
> > client_run waiting on 3218
>
Reply | Threaded
Open this post in threaded view
|

Re: Troubleshooting rsync

Todd C. Miller-3
In reply to this post by Greg Thomas-2
On Fri, 04 Sep 2020 22:57:03 -0700, Greg Thomas wrote:

> Hey all, I'm trying to use WSL on Windows 10 to backup to my OpenBSD server
> running 6.7 release.  It looks like Debian on WSL is using rsync version
> 3.1.2.  I tried both the rsync package and openrsync on OpenBSD with the
> same results.    Basically rsync never exits and when I use four Vs for
> verbosity the last line is 'client_run waiting on..."   rsync locally works
> fine.

Are you using WSL 1 or WSL 2?  If possible, I'd suggest testing with WSL 2.
You can convert between WSL 1 and 2 pretty easily.

 - todd

Reply | Threaded
Open this post in threaded view
|

Re: Troubleshooting rsync

Greg Thomas-2
Just to add to the archives I set up another Window 10 laptop, set up WSL
but this time used OpenSUSE and rsync works fine.

On Sun, Sep 6, 2020 at 5:32 AM Todd C. Miller <[hidden email]> wrote:

> On Fri, 04 Sep 2020 22:57:03 -0700, Greg Thomas wrote:
>
> > Hey all, I'm trying to use WSL on Windows 10 to backup to my OpenBSD
> server
> > running 6.7 release.  It looks like Debian on WSL is using rsync version
> > 3.1.2.  I tried both the rsync package and openrsync on OpenBSD with the
> > same results.    Basically rsync never exits and when I use four Vs for
> > verbosity the last line is 'client_run waiting on..."   rsync locally
> works
> > fine.
>
> Are you using WSL 1 or WSL 2?  If possible, I'd suggest testing with WSL 2.
> You can convert between WSL 1 and 2 pretty easily.
>
>  - todd
>