Bug 14260 - leading / added to file name causing file not found when setting permissions
Summary: leading / added to file name causing file not found when setting permissions
Status: RESOLVED WORKSFORME
Alias: None
Product: rsync
Classification: Unclassified
Component: core (show other bugs)
Version: 3.1.3
Hardware: All Linux
: P5 normal (vote)
Target Milestone: ---
Assignee: Wayne Davison
QA Contact: Rsync QA Contact
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2020-02-01 07:33 UTC by Zoltan Dezsi
Modified: 2020-04-07 23:21 UTC (History)
0 users

See Also:


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Zoltan Dezsi 2020-02-01 07:33:19 UTC
Hi,
I think i have found a bug in the rsync. 
Brief: the rsync is started by root with --daemon. If "use chroot = yes" in /etc/rsyncd.conf, then during the transfer for changing the file permissions a "/" sign prefixes the temporary file name that has been copied, therefore the file is not found:

set modtime of .20200125_110331.jpg.kkjGaK to (1579946612) Sat Jan 25 10:03:32 2020
rsync: failed to set permissions on "/.20200125_110331.jpg.kkjGaK" (in kepek): No such file or directory (2)
renaming .20200125_110331.jpg.kkjGaK to 20200125_110331.jpg

The server runs on a router(OpenWRT), the client is either an Ubuntu under WSL in Windows 10 or a native Debian

For details, please look below.

Detailed logs:
Client:

zoli@DESKTOP-365CN3F:/mnt/c/Users/Zoli/Pictures/2020/_all$ rsync -a -v -v  --numeric-ids -v -v 20200125_110331.jpg 192.168.1.1::kepek
opening tcp connection to 192.168.1.1 port 873
Connected to 192.168.1.1 (192.168.1.1)
msg checking charset: UTF-8
sending daemon args: --server -vvvvlogDtpre.iLsfxC --numeric-ids . kepek/  (5 args)
(Client) Protocol versions: remote=31, negotiated=31
sending incremental file list
[sender] make_file(20200125_110331.jpg,*,0)
[sender] flist start=1, used=1, low=0, high=0
[sender] i=1 <NULL> 20200125_110331.jpg mode=0100777 len=2,649,522 uid=1000 gid=1000 flags=5
send_file_list done
[sender] flist_eof=1
file list sent
send_files starting
server_recv(2) starting pid=8287
process has 1 gid:  1000
gid 1000() maps to 1000
recv_file_name(20200125_110331.jpg)
received 1 names
[Receiver] flist start=1, used=1, low=0, high=0
[Receiver] i=1 1 20200125_110331.jpg mode=0100777 len=2,649,522 gid=1000 flags=0
recv_file_list done
[Receiver] flist_eof=1
get_local_name count=1 /
generator starting pid=8287
delta-transmission enabled
recv_generator(20200125_110331.jpg,1)
send_files(1, 20200125_110331.jpg)
count=0 n=0 rem=0
send_files mapped 20200125_110331.jpg of size 2649522
calling match_sums 20200125_110331.jpg
20200125_110331.jpg
generate_files phase=1
recv_files(1) starting
recv_files(20200125_110331.jpg)
data recv 32768 at 0
data recv 32768 at 32768
...
data recv 32768 at 1605632
data recv 32768 at 1638400
sending file_sum
false_alarms=0 hash_hits=0 matches=0
sender finished 20200125_110331.jpg
data recv 32768 at 1671168
data recv 32768 at 1703936
...
data recv 28082 at 2621440
got file_sum
set modtime of .20200125_110331.jpg.kkjGaK to (1579946612) Sat Jan 25 10:03:32 2020
rsync: failed to set permissions on "/.20200125_110331.jpg.kkjGaK" (in kepek): No such file or directory (2)
renaming .20200125_110331.jpg.kkjGaK to 20200125_110331.jpg
send_files phase=1
recv_files phase=1
generate_files phase=2
send_files phase=2
send files finished
total: matches=0  hash_hits=0  false_alarms=0 data=2649522
recv_files phase=2
recv_files finished
generate_files phase=3
generate_files finished

sent 2,650,259 bytes  received 3,406 bytes  1,769,110.00 bytes/sec
total size is 2,649,522  speedup is 1.00
[sender] _exit_cleanup(code=0, file=main.c, line=1196): entered
rsync error: some files/attrs were not transferred (see previous errors) (code 23) at main.c(1196) [sender=3.1.2]
[sender] _exit_cleanup(code=0, file=main.c, line=1196): about to call exit(23)



Server:

Fri Jan 31 22:57:34 2020 local5.info rsyncd[8287]: connect from DESKTOP-365CN3F (192.168.1.173)
Fri Jan 31 22:57:34 2020 local5.info rsyncd[8287]: rsync to kepek/ from DESKTOP-365CN3F (192.168.1.173)
Fri Jan 31 22:57:34 2020 local5.info rsyncd[8287]: (Server) Protocol versions: remote=31, negotiated=31
Fri Jan 31 22:57:34 2020 local5.info rsyncd[8287]: server_recv(2) starting pid=8287
Fri Jan 31 22:57:34 2020 local5.info rsyncd[8287]: receiving file list
Fri Jan 31 22:57:34 2020 local5.info rsyncd[8287]: process has 1 gid:  1000
Fri Jan 31 22:57:34 2020 local5.info rsyncd[8287]: gid 1000() maps to 1000
Fri Jan 31 22:57:34 2020 local5.info rsyncd[8287]: recv_file_name(20200125_110331.jpg)
Fri Jan 31 22:57:34 2020 local5.info rsyncd[8287]: received 1 names
Fri Jan 31 22:57:34 2020 local5.info rsyncd[8287]: [Receiver] flist start=1, used=1, low=0, high=0
Fri Jan 31 22:57:34 2020 local5.info rsyncd[8287]: [Receiver] i=1 1 20200125_110331.jpg mode=0100777 len=2,649,522 gid=1000 flags=0
Fri Jan 31 22:57:34 2020 local5.info rsyncd[8287]: recv_file_list done
Fri Jan 31 22:57:34 2020 local5.info rsyncd[8287]: [Receiver] flist_eof=1
Fri Jan 31 22:57:34 2020 local5.info rsyncd[8287]: get_local_name count=1 /
Fri Jan 31 22:57:34 2020 local5.info rsyncd[8287]: generator starting pid=8287
Fri Jan 31 22:57:34 2020 local5.info rsyncd[8287]: delta-transmission enabled
Fri Jan 31 22:57:34 2020 local5.info rsyncd[8287]: recv_generator(20200125_110331.jpg,1)
Fri Jan 31 22:57:34 2020 local5.info rsyncd[8287]: generate_files phase=1
Fri Jan 31 22:57:34 2020 local5.info rsyncd[8287]: recv_files(1) starting
Fri Jan 31 22:57:34 2020 local5.info rsyncd[8287]: recv_files(20200125_110331.jpg)
Fri Jan 31 22:57:34 2020 local5.info rsyncd[8287]: data recv 32768 at 0
Fri Jan 31 22:57:34 2020 local5.info rsyncd[8287]: data recv 32768 at 32768
Fri Jan 31 22:57:34 2020 local5.info rsyncd[8287]: data recv 32768 at 65536
...
Fri Jan 31 22:57:34 2020 local5.info rsyncd[8287]: data recv 28082 at 2621440
Fri Jan 31 22:57:34 2020 local5.info rsyncd[8287]: got file_sum
Fri Jan 31 22:57:34 2020 local5.info rsyncd[8287]: set modtime of .20200125_110331.jpg.kkjGaK to (1579946612) Sat Jan 25 10:03:32 2020
Fri Jan 31 22:57:34 2020 local5.warn rsyncd[8287]: rsync: failed to set permissions on "/.20200125_110331.jpg.kkjGaK" (in kepek): No such file or directory (2)
Fri Jan 31 22:57:34 2020 local5.info rsyncd[8287]: renaming .20200125_110331.jpg.kkjGaK to 20200125_110331.jpg
Fri Jan 31 22:57:34 2020 local5.info rsyncd[8287]: recv_files phase=1
Fri Jan 31 22:57:34 2020 local5.info rsyncd[8287]: generate_files phase=2
Fri Jan 31 22:57:35 2020 local5.info rsyncd[8287]: recv_files phase=2
Fri Jan 31 22:57:35 2020 local5.info rsyncd[8287]: recv_files finished
Fri Jan 31 22:57:35 2020 local5.info rsyncd[8287]: generate_files phase=3
Fri Jan 31 22:57:35 2020 local5.info rsyncd[8287]: generate_files finished
Fri Jan 31 22:57:35 2020 local5.info rsyncd[8287]: [generator] _exit_cleanup(code=0, file=main.c, line=1082): entered
Fri Jan 31 22:57:35 2020 local5.info rsyncd[8287]: sent 3584 bytes  received 2650267 bytes  total size 2649522
Fri Jan 31 22:57:35 2020 local5.info rsyncd[8287]: [generator] _exit_cleanup(code=0, file=main.c, line=1082): about to call exit(0)
Comment 1 Wayne Davison 2020-04-07 23:21:34 UTC
That's just rsync reporting the path inside the chrooted module, which is always rooted to the top of the module. You have some other issue to diagnose (it works fine for me). Maybe something is actively monitoring that directory and removing temporary files? You might try using --inplace so that the files get written without a leading dot.