Rsync daemon error

Question

The daemon is being started as root.

[root@uhspaastream02 etc]# systemctl status -l UHS_FolderMonitor.service
    ● UHS_FolderMonitor.service - Starts the folder monitoring/logging script
       Loaded: loaded (/etc/systemd/system/UHS_FolderMonitor.service; static; vendor preset: disabled)
       Active: inactive (dead) since Fri 2018-02-02 15:42:49 EST; 41s ago
         Docs: man:systemd.service
      Process: 11491 ExecStart=/usr/etc/UHS_FolderMonitor.ksh (code=exited, status=0/SUCCESS)
    Main PID: 11491 (code=exited, status=0/SUCCESS)

    Feb 02 15:42:49 uhspaastream02.corp.uhsinc.biz systemd[1]: Starting Starts the folder monitoring/logging script...
    Feb 02 15:42:49 uhspaastream02.corp.uhsinc.biz rsyncd[11492]: rsync: failed to open log-file /var/log/rsync_activity.log: Permission denied (13)
    Feb 02 15:42:49 uhspaastream02.corp.uhsinc.biz rsyncd[11492]: Ignoring "log file" setting.
    Feb 02 15:42:49 uhspaastream02.corp.uhsinc.biz rsyncd[11492]: building file list
    Feb 02 15:42:49 uhspaastream02.corp.uhsinc.biz rsyncd[11492]: rsync: link_stat "/nfs/client_fs/NFSPRODW/UHS_FolderMonitor.ksh" failed: Permission denied (13)
    Feb 02 15:42:49 uhspaastream02.corp.uhsinc.biz rsyncd[11492]: rsync: ERROR: cannot stat destination "/NFSPRODW": Permission denied (13)
    Feb 02 15:42:49 uhspaastream02.corp.uhsinc.biz rsyncd[11492]: rsync error: errors selecting input/output files, dirs (code 3) at main.c(565) [Receiver=3.0.9]
    Feb 02 15:42:49 uhspaastream02.corp.uhsinc.biz systemd[1]: Started Starts the folder monitoring/logging script.

Content of /etc/rsyncd.conf:

# /etc/rsyncd: configuration file for rsync daemon mode
# See rsyncd.conf man page for more options.
#pid file = /var/run/rsyncd.pid
log file = /var/log/rsyncd.log
#log file = /var/log/samba/uhsrsync.log
uid = root
gid = root
use chroot = yes
max connections = 8
exclude = lost+found/
transfer logging = yes
timeout = 900
ignore nonreadable = yes
#log format = %o %h [%a] %m %b %f %l
dont compress   = *.gz *.tgz *.zip *.z *.Z *.rpm *.deb *.bz2
# [ftp]
#        path = /home/ftp
#        comment = ftp export area

Content of /etc/systemd/system/UHS_FolderMonitor.service:

[Unit]
Description= Starts the folder monitoring/logging script
Documentation= man:systemd.service

[Service]
Type=oneshot
ExecStart=/usr/etc/UHS_FolderMonitor.ksh

Output of ksh /usr/etc/UHS_FolderMonitor.ksh:

 [root@uhspaastream02 NFSPRODW]$ ksh /usr/etc/UHS_FolderMonitor.ksh
 sending incremental file list
 rsync: link_stat "/nfs/client_fs/NFSPRODW/*.*" failed: No such file or 
 directory (2)

 sent 12 bytes  received 12 bytes  48.00 bytes/sec
 total size is 0  speedup is 0.00
 rsync error: some files/attrs were not transferred (see previous errors) 
 (code 23) at main.c(1052) [sender=3.0.9]

Content of /var/log/rsync_activity.log:

 [root@uhspaastream02 NFSPRODW]$ cat /var/log/rsync_activity.log
 2018/02/02 13:30:03 [3422] building file list
 2018/02/02 13:30:03 [3422] >f+++++++++ HHN Center_COWIN, JUSTIN 
 TYME_HHN8026539_HHN0005000372168_9.14.2017_p152w-258306975.pdf
 2018/02/02 13:30:03 [3422] sent 130.00K bytes  received 31 bytes  260.06K 
 bytes/sec
 2018/02/02 13:30:03 [3422] total size is 149.91K  speedup is 1.15
 2018/02/02 17:06:22 [13342] building file list
 2018/02/02 17:06:22 [13342] >f+++++++++ RTMS Project Update.docx
 2018/02/02 17:06:22 [13342] sent 11.17K bytes  received 31 bytes  22.40K 
 bytes/sec
 2018/02/02 17:06:22 [13342] total size is 14.00K  speedup is 1.25
 2018/02/12 09:33:22 [8120] building file list
 2018/02/12 09:33:22 [8120] rsync: link_stat "/nfs/client_fs/NFSPRODW/*.*" 
 failed: No such file or directory (2)
 2018/02/12 09:33:22 [8120] sent 12 bytes  received 12 bytes  48.00 
 bytes/sec
 2018/02/12 09:33:22 [8120] total size is 0  speedup is 0.00
 2018/02/12 09:33:22 [8120] rsync error: some files/attrs were not 
 transferred (see previous errors) (code 23) at main.c(1052) [sender=3.0.9]
 2018/02/12 09:37:02 [8206] building file list
 2018/02/12 09:37:02 [8206] rsync: link_stat "/nfs/client_fs/NFSPRODW/*.*" 
 failed: No such file or directory (2)
 2018/02/12 09:37:02 [8206] sent 12 bytes  received 12 bytes  48.00 
 bytes/sec
 2018/02/12 09:37:02 [8206] total size is 0  speedup is 0.00
 2018/02/12 09:37:02 [8206] rsync error: some files/attrs were not 
 transferred (see previous errors) (code 23) at main.c(1052) [sender=3.0.9]
 2018/02/12 09:37:35 [8218] building file list
 2018/02/12 09:37:35 [8218] rsync: link_stat "/nfs/client_fs/NFSPRODW/*.*" 
 failed: No such file or directory (2)
 2018/02/12 09:37:35 [8218] sent 12 bytes  received 12 bytes  48.00 
 bytes/sec
 2018/02/12 09:37:35 [8218] total size is 0  speedup is 0.00
 2018/02/12 09:37:35 [8218] rsync error: some files/attrs were not 
 transferred (see previous errors) (code 23) at main.c(1052) [sender=3.0.9]

Permission of NFSPRODW:

 [root@uhspaastream02 NFSPRODW]$ ls -ld /nfs/client_fs/NFSPRODW/
 drwxrwxrwx. 2 root root 4096 Feb 12 09:37 /nfs/client_fs/NFSPRODW/

Permission of UHS_FolderMonitor.ksh:

 [root@uhspaastream02 NFSPRODW]$ ls -ld /usr/etc/UHS_FolderMonitor.ksh
 -rwxrwxrwx. 1 root root 724 Feb  2 16:31 /usr/etc/UHS_FolderMonitor.ksh

Code of UHS_FolderMonitor.ksh:

 [root@uhspaastream02 NFSPRODW]$ cat /usr/etc/UHS_FolderMonitor.ksh
 #!/bin/ksh
 # Description: Script that moves files to Windows NFS share via the systemd 
 UHS_FolderMonitor service file
 #              Service Filename is 
 /etc/systemd/system/UHS_FolderMonitor.service
 #              Service file above relies on the 
 /etc/systemd/system/UHS_FolderMonitor.path file
 #
 # Scriptname: /usr/etc/UHS_FolderMonitor.ksh
 #
 # Owner: 
 # Version 1.0
 # Last Updated:  01/24/18
 #
 #Change Log: Initial Create 01/24/18
 #
 # mv /nfs/client_fs/NFSPRODW/*.* /NFSPRODW
 /usr/bin/rsync --chmod=u=rwx,g=rwx,o=rwx --remove-source-files -r -zvh --
 log-file=/var/log/rsync_activity.log /nfs/client_fs/NFSPRODW/*.* /NFSPRODW
 echo `date` ' Rsync - File(s) moved to NFS Share' >>  
 /usr/etc/UHS_FolderMonitor.log

I’m thinking this must be permissions causing this for the user running rsyncd daemon since the manually executed rsync command works just fine.

Thanks.

Answer 1

First of all, local version.

I’ve omitted ‘--remove-source-files’ in script for testing:

[root@centos7 rsync_task]# pwd
/root/rsync_task
[root@centos7 rsync_task]# ls -la backup.sh
-rw-r--r-x 1 root root 259 Feb 13 01:15 backup.sh
[root@centos7 rsync_task]# cat backup.sh
#!/bin/sh
echo "List files in src: "$(ls /mnt/backup_src)
/usr/bin/rsync --chmod=u=rwx,g=rwx,o=rwx -r -zvh --log-file=/var/log/rsync_activity.log /mnt/backup_src/* /mnt/backup_dst
echo `date` ' Rsync - File(s) moved to NFS Share' >> /var/log/rsync_backup.log

Service file:

[root@centos7 rsync_task]# ls -lah /etc/systemd/system/rsync_backup.service
-rw-r--r-- 1 root root 160 Feb 13 00:52 /etc/systemd/system/rsync_backup.service
[root@centos7 rsync_task]# cat /etc/systemd/system/rsync_backup.service
[Unit]
Description= Starts the folder monitoring/logging script
Documentation= man:systemd.service

[Service]
Type=oneshot
ExecStart=/root/rsync_task/backup.sh

Little check before start service:

[root@centos7 mnt]# pwd
/mnt
[root@centos7 mnt]# ls -lad backup_*
drwxr-xr-x 2 root root  6 Feb 13 01:15 backup_dst
drwxr-xr-x 2 root root 71 Feb 13 01:12 backup_src
[root@centos7 mnt]# ls backup_src/
file1  file2  file3  file4  file5
[root@centos7 mnt]# ls backup_dst

Starting service:

[root@centos7 yurij]# systemctl start rsync_backup.service
[root@centos7 yurij]# systemctl status rsync_backup.service
● rsync_backup.service - Starts the folder monitoring/logging script
   Loaded: loaded (/etc/systemd/system/rsync_backup.service; static; vendor preset: disabled)
   Active: inactive (dead)
     Docs: man:systemd.service

Feb 13 01:24:11 centos7.localdomain backup.sh[2714]: List files in src: file1 file2 file3 file4 file5
Feb 13 01:24:11 centos7.localdomain backup.sh[2714]: sending incremental file list
Feb 13 01:24:11 centos7.localdomain backup.sh[2714]: file1
Feb 13 01:24:11 centos7.localdomain backup.sh[2714]: file2
Feb 13 01:24:11 centos7.localdomain backup.sh[2714]: file3
Feb 13 01:24:11 centos7.localdomain backup.sh[2714]: file4
Feb 13 01:24:11 centos7.localdomain backup.sh[2714]: file5
Feb 13 01:24:11 centos7.localdomain backup.sh[2714]: sent 236 bytes  received 107 bytes  686.00 bytes/sec
Feb 13 01:24:11 centos7.localdomain backup.sh[2714]: total size is 0  speedup is 0.00
Feb 13 01:24:11 centos7.localdomain systemd[1]: Started Starts the folder monitoring/logging script.

Let's check backups:

[root@centos7 mnt]# ls backup_dst
file1  file2  file3  file4  file5

Copy to NFS share (‘debian9’ is used as NFS-server).

NFS-sever configuration:

root@debian9:~/backups# pwd
/root/backups
root@debian9:~/backups# ls -ld ./
drwxrwxrwx 2 root root 4096 Feb 13 01:35 ./
root@debian9:~/backups# cat /etc/exports
/root/backups 192.168.56.0/24(rw,sync,no_subtree_check,no_root_squash,insecure)
root@debian9:~/backups# systemctl status nfs-server
● nfs-server.service - NFS server and services
   Loaded: loaded (/lib/systemd/system/nfs-server.service; enabled; vendor preset: enabled)
   Active: active (exited) since Tue 2018-02-13 01:32:10 MSK; 6min ago
  Process: 1631 ExecStopPost=/usr/sbin/exportfs -f (code=exited, status=0/SUCCESS)
  Process: 1628 ExecStopPost=/usr/sbin/exportfs -au (code=exited, status=0/SUCCESS)
  Process: 1625 ExecStop=/usr/sbin/rpc.nfsd 0 (code=exited, status=0/SUCCESS)
  Process: 1645 ExecStart=/usr/sbin/rpc.nfsd $RPCNFSDARGS (code=exited, status=0/SUCCESS)
  Process: 1643 ExecStartPre=/usr/sbin/exportfs -r (code=exited, status=0/SUCCESS)
 Main PID: 1645 (code=exited, status=0/SUCCESS)

Feb 13 01:32:10 debian9 systemd[1]: Starting NFS server and services...
Feb 13 01:32:10 debian9 systemd[1]: Started NFS server and services.

State of first host on which we doing backups:

[root@centos7 mnt]# pwd
/mnt
[root@centos7 mnt]# ls backup_src
file1  file2  file3  file4  file5
[root@centos7 mnt]# ls backup_dst
[root@centos7 mnt]# mount|grep nfs
nfsd on /proc/fs/nfsd type nfsd (rw,relatime)
sunrpc on /var/lib/nfs/rpc_pipefs type rpc_pipefs (rw,relatime)
[root@centos7 mnt]# mount -t nfs 192.168.56.4:/root/backups backup_dst/
[root@centos7 mnt]# ls backup_dst
[root@centos7 mnt]# mount|grep nfs
nfsd on /proc/fs/nfsd type nfsd (rw,relatime)
sunrpc on /var/lib/nfs/rpc_pipefs type rpc_pipefs (rw,relatime)
192.168.56.4:/root/backups on /mnt/backup_dst type nfs4 (rw,relatime,vers=4.1,rsize=524288,wsize=524288,namlen=255,hard,proto=tcp,port=0,timeo=600,retrans=2,sec=sys,clientaddr=192.168.56.5,local_lock=none,addr=192.168.56.4)

Let's start the service:

[root@centos7 yurij]# systemctl start rsync_backup.service
[root@centos7 yurij]# systemctl status rsync_backup.service
● rsync_backup.service - Starts the folder monitoring/logging script
   Loaded: loaded (/etc/systemd/system/rsync_backup.service; static; vendor preset: disabled)
   Active: inactive (dead)
     Docs: man:systemd.service

Feb 13 01:43:25 centos7.localdomain backup.sh[2874]: List files in src: file1 file2 file3 file4 file5
Feb 13 01:43:25 centos7.localdomain backup.sh[2874]: sending incremental file list
Feb 13 01:43:25 centos7.localdomain backup.sh[2874]: file1
Feb 13 01:43:25 centos7.localdomain backup.sh[2874]: file2
Feb 13 01:43:25 centos7.localdomain backup.sh[2874]: file3
Feb 13 01:43:25 centos7.localdomain backup.sh[2874]: file4
Feb 13 01:43:25 centos7.localdomain backup.sh[2874]: file5
Feb 13 01:43:26 centos7.localdomain backup.sh[2874]: sent 236 bytes  received 107 bytes  228.67 bytes/sec
Feb 13 01:43:26 centos7.localdomain backup.sh[2874]: total size is 0  speedup is 0.00
Feb 13 01:43:26 centos7.localdomain systemd[1]: Started Starts the folder monitoring/logging script.

[root@centos7 mnt]# ls backup_dst
file1  file2  file3  file4  file5

Checking on NFS-server:

root@debian9:~/backups# pwd
/root/backups
root@debian9:~/backups# ls
file1  file2  file3  file4  file5

Finally, trying as ‘rsyncd’ which will be live in ‘debian9’ host:

root@debian9:~/backups# cat /etc/rsyncd.conf
log file=/var/log/rsyncd
[Backups]
    comment = backups
    path = /root/backups/
    use chroot = yes
    lock file = /var/lock/rsyncd
    read only = no
    write only = yes
    list = yes
    uid = root
    gid = root
    strict modes = yes
    hosts allow = 192.168.56.5 #it's my 'centos7'
    ignore errors = no
    ignore nonreadable = yes
    transfer logging = no
    timeout = 600
    refuse options = checksum dry-run
    dont compress = *.gz *.tgz *.zip *.z *.rpm *.deb *.iso *.bz2 *.tbz
root@debian9:~/backups# systemctl status rsync
● rsync.service - fast remote file copy program daemon
   Loaded: loaded (/lib/systemd/system/rsync.service; enabled; vendor preset: enabled)
   Active: active (running) since Tue 2018-02-13 02:06:42 MSK; 33s ago
 Main PID: 2327 (rsync)
    Tasks: 1 (limit: 4915)
   CGroup: /system.slice/rsync.service
           └─2327 /usr/bin/rsync --daemon --no-detach

Feb 13 02:06:42 debian9 systemd[1]: Stopped fast remote file copy program daemon.
Feb 13 02:06:42 debian9 systemd[1]: Started fast remote file copy program daemon.

Check in backup directory on ‘debian9’:

root@debian9:~/backups# pwd
/root/backups
root@debian9:~/backups# ls

Make little changes in backup script:

[root@centos7 rsync_task]# cat backup.sh
#!/bin/sh
echo "List files in src: "$(ls /mnt/backup_src)
/usr/bin/rsync --chmod=u=rwx,g=rwx,o=rwx -r -zvh --log-file=/var/log/rsync_activity.log /mnt/backup_src/* rsync://192.168.56.4/Backups
echo `date` ' Rsync - File(s) moved to NFS Share' >> /var/log/rsync_backup.log

Check in source files:

[root@centos7 mnt]# pwd
/mnt
[root@centos7 mnt]# ls backup_src/
file1  file2  file3  file4  file5

Let's start service:

[root@centos7 yurij]# systemctl start rsync_backup.service
[root@centos7 yurij]# systemctl status rsync_backup.service
● rsync_backup.service - Starts the folder monitoring/logging script
   Loaded: loaded (/etc/systemd/system/rsync_backup.service; static; vendor preset: disabled)
   Active: inactive (dead)
     Docs: man:systemd.service

Feb 13 02:10:13 centos7.localdomain backup.sh[3021]: List files in src: file1 file2 file3 file4 file5
Feb 13 02:10:13 centos7.localdomain backup.sh[3021]: sending incremental file list
Feb 13 02:10:13 centos7.localdomain backup.sh[3021]: file1
Feb 13 02:10:13 centos7.localdomain backup.sh[3021]: file2
Feb 13 02:10:13 centos7.localdomain backup.sh[3021]: file3
Feb 13 02:10:13 centos7.localdomain backup.sh[3021]: file4
Feb 13 02:10:13 centos7.localdomain backup.sh[3021]: file5
Feb 13 02:10:13 centos7.localdomain backup.sh[3021]: sent 232 bytes  received 103 bytes  670.00 bytes/sec
Feb 13 02:10:13 centos7.localdomain backup.sh[3021]: total size is 0  speedup is 0.00
Feb 13 02:10:13 centos7.localdomain systemd[1]: Started Starts the folder monitoring/logging script.

Check in files on backup (rsynd) server:

root@debian9:~/backups# pwd
/root/backups
root@debian9:~/backups# ls
file1  file2  file3  file4  file5

Answer 2

For what it's worth, I'd check the SELinux context on your script file /usr/etc/UHS_FolderMonitor.ksh . I had a similar problem with a systemd unit file using rsync.

Also see man 8 rsync_selinux (selinux-policy-doc package) for useful booleans.