Problems using Syncthing on Synology


(Audrius Butkevicius) #21

Sure, but the normal permissions still exist in the kernel, so regardless of how you manage them the kernel still should respect basic posix permissions, and now it looks like the folder tree is owned by different users. I am not sure where the root of the folder is, or what user syncthig is running as, but it could be the cause.

As for strace, perhaps you should run strace with the -f option to catch all threads and subprocesses, as the top process in syncthing is a monitor process that does not do much.


(Bob Hope) #22

Hello

Maybe you can find out which user is running Syncthing on the Synology? (This might help: Link external)

After that, CHMOD might be of help to change the Access of that user to the directory. Today, different users have access to the folders:

image


#23

I thought about changing permissions as well. However, I’m a bit reluctant to do so since there are a lot of Synology’s internal folders and I have no idea what impact the change of permissions would have.

I just tried entware-ng’s syncthing, same issue.


#24

syncthing is run as user sc-syncthing, permissions are controlled via ACL’s and group sc-syncthing.


#25

Although it is discouraged, should I try running syncthing as root?


(Bob Hope) #26

On my Synology I created the user Syno and then did CHOWN (https://wiki.ubuntuusers.de/chown/) and later CHOMD -R (https://wiki.ubuntuusers.de/chmod/)

You might wanna use the user sc-syncthing instead.

I didn’t consider if it might affect the Synology too much, so please use at own risk.


(Bob Hope) #27

I would not recommend.


(Audrius Butkevicius) #28

You shouldn’t, you should run syncthing as the user who owns the folders. I don’t think the permissions are ok in this case, and it would have been nice if you provided the full picture.


#29

OK, I’ll try:

  • Syncthing is installed via SynoCommunity’s package syncthing.
  • Following the Synology guidelines for 3rd party packages it is run as hidden user sc-syncthing.
  • Permissions are controlled via ACL and the group sc-syncthing.
  • This is all a must according to SynoCommunity.
  • The default path for shared folders is /volume1.
  • Whereby /volume1 is the default mountpoint on Synology-NAS.
  • /volume1 is formatted as btrfs
  • AFAIK Synology supports inotify and uses it in its own products. There are also other 3rd party apps that utilize it, e. g. Crashplan.
  • The shared folder in question is /volume1/KUNDEN_1 on one NAS and /volume1/DCBK_KUNDEN_1 on the other.
  • Setting up inotify-watches seems to fail for unknown reasons.
  • POSIX permissions are a bit weird and the impact of changing them is unclear.

Is that picture more complete?

I attached all EPERM errors from running strace -f sh -c 'STTRACE=all /usr/local/syncthing/bin/syncthing ...'.


#30

syncthing_eperm.log (188.8 KB)


#31

And here is part of the log where inotify shows up for the first time:

[pid 21201] inotify_add_watch(13, "/volume1/KUNDEN_1", IN_MODIFY|IN_MOVED_FROM|IN_MOVED_TO|IN_CREATE|IN_DELETE|IN_DELETE_SELF|IN_MOVE_SELF <unfinished ...>
[pid 21186] sched_yield( <unfinished ...>
[pid 21189] newfstatat(AT_FDCWD, "/volume1/KUNDEN_1/.stfolder",  <unfinished ...>
[pid 21201] <... inotify_add_watch resumed> ) = 1
[pid 21186] <... sched_yield resumed> ) = 0
[pid 21201] openat(AT_FDCWD, "/volume1/KUNDEN_1", O_RDONLY|O_CLOEXEC <unfinished ...>
[pid 21189] <... newfstatat resumed> {st_mode=S_IFDIR|0777, st_size=0, ...}, 0) = 0
[pid 21201] <... openat resumed> )      = 17
[pid 21175] write(1, "[2H2JG] 2018/12/06 08:51:50.7992"..., 147[2H2JG] 2018/12/06 08:51:50.799247 logfs.go:163: DEBUG: wrapper.go:504 basic /usr/local/syncthing/var Usage . {4817413603328 11508045873152} <nil>
 <unfinished ...>
[pid 21201] epoll_ctl(4, EPOLL_CTL_ADD, 17, {EPOLLIN|EPOLLOUT|EPOLLRDHUP|EPOLLET, {u32=4080893584, u64=140157453696656}} <unfinished ...>
[pid 21175] <... write resumed> )       = 147
[pid 21201] <... epoll_ctl resumed> )   = -1 EPERM (Operation not permitted)
[pid 21189] write(1, "[2H2JG] 2018/12/06 08:51:50.8023"..., 143 <unfinished ...>
[pid 21201] epoll_ctl(4, EPOLL_CTL_DEL, 17, {0, {u32=0, u64=0}} <unfinished ...>
[pid 21189] <... write resumed> )       = 143
[pid 21201] <... epoll_ctl resumed> )   = -1 EPERM (Operation not permitted)
[pid 21175] write(1, "[2H2JG] 2018/12/06 08:51:50.8002"..., 118[2H2JG] 2018/12/06 08:51:50.800270 folder.go:169: DEBUG: sendreceive/fojr7-rpgdy@0xc00011f080 Scanning subdirectories
 <unfinished ...>
[pid 21201] getdents64(17,  <unfinished ...>
[pid 21189] statfs("/usr/local/syncthing/var",  <unfinished ...>
[pid 21175] <... write resumed> )       = 118
[pid 21201] <... getdents64 resumed> /* 26 entries */, 8192) = 904
[pid 21189] <... statfs resumed> {f_type=0x9123683e, f_bsize=4096, f_blocks=2809581512, f_bfree=1176126368, f_bavail=1176126368, f_files=0, f_ffree=0, f_fsid={1376123253, -619084993}, f_namelen=255, f_frsize=4096}) = 0
[pid 21201] getdents64(17,  <unfinished ...>
[pid 21175] write(1, "[2H2JG] 2018/12/06 08:51:50.8010"..., 135[2H2JG] 2018/12/06 08:51:50.801030 logfs.go:115: DEBUG: folderconfiguration.go:151 basic /volume1/KUNDEN_1 Stat . {0xc0000b3450} <nil>
 <unfinished ...>
[pid 21201] <... getdents64 resumed> /* 0 entries */, 8192) = 0
[pid 21175] <... write resumed> )       = 135
[pid 21201] close(17 <unfinished ...>
[pid 21175] read(7,  <unfinished ...>
[pid 21201] <... close resumed> )       = 0
[pid 21189] write(1, "[2H2JG] 2018/12/06 08:51:50.8027"..., 147 <unfinished ...>
[pid 21175] <... read resumed> "[2H2JG] 2018/12/06 08:51:50.8023"..., 4096) = 143
[pid 21189] <... write resumed> )       = 147
[pid 21175] write(1, "[2H2JG] 2018/12/06 08:51:50.8023"..., 143[2H2JG] 2018/12/06 08:51:50.802322 logfs.go:115: DEBUG: folderconfiguration.go:169 basic /volume1/KUNDEN_1 Stat .stfolder {0xc0000b36c0} <nil>
) = 143
[pid 21175] read(7, "[2H2JG] 2018/12/06 08:51:50.8027"..., 4096) = 147
[pid 21201] sched_yield( <unfinished ...>
[pid 21175] write(1, "[2H2JG] 2018/12/06 08:51:50.8027"..., 147[2H2JG] 2018/12/06 08:51:50.802718 logfs.go:163: DEBUG: wrapper.go:504 basic /usr/local/syncthing/var Usage . {4817413603328 11508045873152} <nil>
 <unfinished ...>
[pid 21201] <... sched_yield resumed> ) = 0
[pid 21175] <... write resumed> )       = 147
[pid 21201] futex(0x133e7d8, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
[pid 21189] futex(0x133e7d8, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid 21201] <... futex resumed> )       = -1 EAGAIN (Resource temporarily unavailable)
[pid 21189] <... futex resumed> )       = 0
[pid 21201] futex(0x133e7d8, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid 21175] read(7,  <unfinished ...>
[pid 21201] <... futex resumed> )       = 0
[pid 21175] <... read resumed> 0xc00027e000, 4096) = -1 EAGAIN (Resource temporarily unavailable)
[pid 21189] sched_yield( <unfinished ...>
[pid 21175] epoll_pwait(4, {}, 128, 0, NULL) = 0
[pid 21175] epoll_pwait(4,  <unfinished ...>
[pid 21189] <... sched_yield resumed> ) = 0
[pid 21201] lstat("/volume1/KUNDEN_1/MICHELIN",  <unfinished ...>
[pid 21189] futex(0x133e7d8, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid 21170] <... nanosleep resumed> NULL) = 0
[pid 21201] <... lstat resumed> {st_mode=S_IFDIR|0777, st_size=464, ...}) = 0
[pid 21189] <... futex resumed> )       = 0
[pid 21186] epoll_wait(14,  <unfinished ...>
[pid 21170] futex(0x131b0d0, FUTEX_WAIT_PRIVATE, 0, {60, 0} <unfinished ...>
[pid 21189] rt_sigprocmask(SIG_SETMASK, ~[], [], 8) = 0
[pid 21189] clone(Process 21202 attached
 <unfinished ...>
[pid 21185] lstat("/volume1/KUNDEN_1/BFGoodrich",  <unfinished ...>
[pid 21202] gettid()                    = 21202
[pid 21189] <... clone resumed> child_stack=0xc000010000, flags=CLONE_VM|CLONE_FS|CLONE_FILES|CLONE_SIGHAND|CLONE_THREAD|CLONE_SYSVSEM) = 21202
[pid 21202] arch_prctl(ARCH_SET_FS, 0xc000050e90 <unfinished ...>
[pid 21189] rt_sigprocmask(SIG_SETMASK, [],  <unfinished ...>
[pid 21202] <... arch_prctl resumed> )  = 0
[pid 21189] <... rt_sigprocmask resumed> NULL, 8) = 0
[pid 21202] sigaltstack(NULL <unfinished ...>
[pid 21189] futex(0x131b0e8, FUTEX_WAIT_PRIVATE, 0, {0, 100000} <unfinished ...>
[pid 21202] <... sigaltstack resumed> , {ss_sp=0, ss_flags=SS_DISABLE, ss_size=0}) = 0
[pid 21185] <... lstat resumed> {st_mode=S_IFDIR|0777, st_size=218, ...}) = 0
[pid 21202] sigaltstack({ss_sp=0xc0006f8000, ss_flags=0, ss_size=32768} <unfinished ...>
[pid 21189] <... futex resumed> )       = -1 ETIMEDOUT (Connection timed out)
[pid 21202] <... sigaltstack resumed> , NULL) = 0
[pid 21185] lstat("/volume1/KUNDEN_1/KLEBER",  <unfinished ...>
[pid 21202] rt_sigprocmask(SIG_SETMASK, [],  <unfinished ...>
[pid 21185] <... lstat resumed> {st_mode=S_IFDIR|0777, st_size=388, ...}) = 0
[pid 21202] <... rt_sigprocmask resumed> NULL, 8) = 0
[pid 21202] gettid( <unfinished ...>
[pid 21189] futex(0x131b0e8, FUTEX_WAIT_PRIVATE, 0, {0, 100000} <unfinished ...>
[pid 21202] <... gettid resumed> )      = 21202
[pid 21202] futex(0x131b0e8, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid 21185] sched_yield( <unfinished ...>
[pid 21202] <... futex resumed> )       = 1
[pid 21189] <... futex resumed> )       = 0
[pid 21202] nanosleep({0, 3000},  <unfinished ...>
[pid 21185] <... sched_yield resumed> ) = 0
[pid 21185] futex(0x131aff0, FUTEX_WAKE_PRIVATE, 1) = 0
[pid 21202] <... nanosleep resumed> NULL) = 0
[pid 21185] lstat("/volume1/KUNDEN_1/_StockPhoto_Datenbank",  <unfinished ...>
[pid 21202] write(1, "[2H2JG] 2018/12/06 08:51:50.8047"..., 94 <unfinished ...>
[pid 21185] <... lstat resumed> {st_mode=S_IFDIR|0777, st_size=234, ...}) = 0
[pid 21202] <... write resumed> )       = 94
[pid 21201] openat(AT_FDCWD, "/usr/local/syncthing/var/gui", O_RDONLY|O_CLOEXEC <unfinished ...>
[pid 21175] <... epoll_pwait resumed> {{EPOLLIN, {u32=3257462208, u64=140478752812480}}}, 128, -1, NULL) = 1
[pid 21201] <... openat resumed> )      = -1 ENOENT (No such file or directory)
[pid 21175] futex(0x131b0d0, FUTEX_WAKE_PRIVATE, 1) = 1
[pid 21175] read(7,  <unfinished ...>
[pid 21185] lstat("/volume1/KUNDEN_1/_Schriften_f\303\274r_alle",  <unfinished ...>
[pid 21175] <... read resumed> "[2H2JG] 2018/12/06 08:51:50.8047"..., 4096) = 94
[pid 21175] write(1, "[2H2JG] 2018/12/06 08:51:50.8047"..., 94[2H2JG] 2018/12/06 08:51:50.804753 tcp_listen.go:69: INFO: TCP listener ([::]:22000) starting
) = 94
[pid 21202] futex(0x131f020, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid 21185] <... lstat resumed> {st_mode=S_IFDIR|0777, st_size=826, ...}) = 0
[pid 21202] <... futex resumed> )       = 1
[pid 21184] <... futex resumed> )       = 0
[pid 21175] read(7,  <unfinished ...>
[pid 21184] futex(0xc0000504c0, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
[pid 21185] sched_yield( <unfinished ...>
[pid 21175] <... read resumed> 0xc00027e000, 4096) = -1 EAGAIN (Resource temporarily unavailable)
[pid 21175] epoll_pwait(4, {}, 128, 0, NULL) = 0
[pid 21202] accept4(12,  <unfinished ...>
[pid 21185] <... sched_yield resumed> ) = 0
[pid 21201] write(1, "[2H2JG] 2018/12/06 08:51:50.8053"..., 165 <unfinished ...>
[pid 21202] <... accept4 resumed> 0xc0001af858, [112], SOCK_CLOEXEC|SOCK_NONBLOCK) = -1 EAGAIN (Resource temporarily unavailable)
[pid 21201] <... write resumed> )       = 165
[pid 21185] futex(0x133e7d8, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid 21202] futex(0xc0000504c0, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid 21185] <... futex resumed> )       = 0
[pid 21202] <... futex resumed> )       = 1
[pid 21184] <... futex resumed> )       = 0
[pid 21175] epoll_pwait(4,  <unfinished ...>
[pid 21201] write(1, "[2H2JG] 2018/12/06 08:51:50.8054"..., 73 <unfinished ...>
[pid 21184] epoll_pwait(4,  <unfinished ...>
[pid 21201] <... write resumed> )       = 73
[pid 21184] <... epoll_pwait resumed> {}, 128, 0, NULL) = 0
[pid 21201] futex(0xc000578840, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
[pid 21202] futex(0x131f020, FUTEX_WAIT_PRIVATE, 0, {0, 999707442} <unfinished ...>
[pid 21189] futex(0x131b0c0, FUTEX_WAIT_PRIVATE, 0, {0, 100000} <unfinished ...>
[pid 21185] futex(0xc000050840, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
[pid 21189] <... futex resumed> )       = -1 EAGAIN (Resource temporarily unavailable)
[pid 21184] futex(0x131b0c0, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid 21189] sched_yield( <unfinished ...>
[pid 21184] <... futex resumed> )       = 0
[pid 21189] <... sched_yield resumed> ) = 0
[pid 21184] futex(0xc0000504c0, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
[pid 21189] futex(0x131aff0, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid 21175] <... epoll_pwait resumed> {{EPOLLIN, {u32=3257462208, u64=140478752812480}}}, 128, -1, NULL) = 1
[pid 21189] <... futex resumed> )       = 0
[pid 21175] read(7,  <unfinished ...>
[pid 21189] futex(0xc0000504c0, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid 21175] <... read resumed> "[2H2JG] 2018/12/06 08:51:50.8053"..., 4096) = 238
[pid 21189] <... futex resumed> )       = 1
[pid 21184] <... futex resumed> )       = 0
[pid 21189] futex(0xc000050840, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid 21170] <... futex resumed> )       = 0
[pid 21189] <... futex resumed> )       = 1
[pid 21175] write(1, "[2H2JG] 2018/12/06 08:51:50.8053"..., 165 <unfinished ...>
[pid 21189] futex(0xc000578840, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid 21185] <... futex resumed> )       = 0
[pid 21201] <... futex resumed> )       = 0
[pid 21189] <... futex resumed> )       = 1
[pid 21201] futex(0x131b4c8, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid 21185] sched_yield( <unfinished ...>
[pid 21201] <... futex resumed> )       = 0
[pid 21189] epoll_pwait(4,  <unfinished ...>
[pid 21201] futex(0xc000578840, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
[pid 21189] <... epoll_pwait resumed> {}, 128, 0, NULL) = 0
[pid 21185] <... sched_yield resumed> ) = 0
[pid 21184] sched_yield( <unfinished ...>
[pid 21189] futex(0x131aff0, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid 21185] futex(0x131aff0, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
[pid 21189] <... futex resumed> )       = 0
[pid 21185] <... futex resumed> )       = -1 EAGAIN (Resource temporarily unavailable)
[pid 21189] rt_sigprocmask(SIG_SETMASK, ~[],  <unfinished ...>
[pid 21185] futex(0x131aff0, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid 21189] <... rt_sigprocmask resumed> [], 8) = 0
[pid 21185] <... futex resumed> )       = 0
[pid 21189] clone( <unfinished ...>
[pid 21185] futex(0xc000050840, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
[pid 21184] <... sched_yield resumed> ) = 0
Process 21203 attached
[pid 21203] gettid( <unfinished ...>
[pid 21189] <... clone resumed> child_stack=0xc000324000, flags=CLONE_VM|CLONE_FS|CLONE_FILES|CLONE_SIGHAND|CLONE_THREAD|CLONE_SYSVSEM) = 21203
[pid 21203] <... gettid resumed> )      = 21203
[pid 21189] rt_sigprocmask(SIG_SETMASK, [],  <unfinished ...>
[pid 21203] arch_prctl(ARCH_SET_FS, 0xc000051210 <unfinished ...>
[pid 21189] <... rt_sigprocmask resumed> NULL, 8) = 0
[pid 21203] <... arch_prctl resumed> )  = 0
[pid 21189] futex(0xc000578840, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid 21203] sigaltstack(NULL <unfinished ...>
[pid 21201] <... futex resumed> )       = 0
[pid 21203] <... sigaltstack resumed> , {ss_sp=0, ss_flags=SS_DISABLE, ss_size=0}) = 0
[pid 21189] <... futex resumed> )       = 1
[pid 21203] sigaltstack({ss_sp=0xc0008de000, ss_flags=0, ss_size=32768} <unfinished ...>
[pid 21189] futex(0xc0000504c0, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid 21203] <... sigaltstack resumed> , NULL) = 0
[pid 21189] <... futex resumed> )       = 0
[pid 21203] rt_sigprocmask(SIG_SETMASK, [],  <unfinished ...>
[pid 21201] openat(AT_FDCWD, "/usr/local/syncthing/var/https-cert.pem", O_RDONLY|O_CLOEXEC <unfinished ...>
[pid 21203] <... rt_sigprocmask resumed> NULL, 8) = 0
[pid 21184] futex(0x131aff0, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid 21203] gettid( <unfinished ...>
[pid 21201] <... openat resumed> )      = 17
[pid 21203] <... gettid resumed> )      = 21203
[pid 21184] <... futex resumed> )       = 0
[pid 21201] epoll_ctl(4, EPOLL_CTL_ADD, 17, {EPOLLIN|EPOLLOUT|EPOLLRDHUP|EPOLLET, {u32=4080893584, u64=140157453696656}} <unfinished ...>
[pid 21203] lstat("/volume1/KUNDEN_1/SALT-KVA-Austausch",  <unfinished ...>
[pid 21175] <... write resumed> )       = 165
[pid 21203] <... lstat resumed> {st_mode=S_IFDIR|0777, st_size=204, ...}) = 0
[pid 21189] write(1, "[2H2JG] 2018/12/06 08:51:50.8065"..., 155 <unfinished ...>
[pid 21170] nanosleep({0, 20000},  <unfinished ...>
[pid 21189] <... write resumed> )       = 155
[pid 21175] write(1, "[2H2JG] 2018/12/06 08:51:50.8054"..., 73[2H2JG] 2018/12/06 08:51:50.805465 service.go:308: DEBUG: Reconnect loop
 <unfinished ...>
[pid 21189] sched_yield( <unfinished ...>
[pid 21175] <... write resumed> )       = 73
[pid 21189] <... sched_yield resumed> ) = 0
[pid 21175] read(7,  <unfinished ...>
[pid 21203] futex(0x133e7d8, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid 21189] futex(0x133e7d8, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
[pid 21203] <... futex resumed> )       = 0
[pid 21189] <... futex resumed> )       = -1 EAGAIN (Resource temporarily unavailable)
[pid 21175] <... read resumed> "[2H2JG] 2018/12/06 08:51:50.8065"..., 4096) = 155
[pid 21189] futex(0x133e7d8, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid 21201] <... epoll_ctl resumed> )   = -1 EPERM (Operation not permitted)
[pid 21189] <... futex resumed> )       = 0
[pid 21201] epoll_ctl(4, EPOLL_CTL_DEL, 17, {0, {u32=0, u64=0}} <unfinished ...>
[pid 21189] sched_yield( <unfinished ...>
[pid 21201] <... epoll_ctl resumed> )   = -1 EPERM (Operation not permitted)
[pid 21189] <... sched_yield resumed> ) = 0
[pid 21184] epoll_pwait(4,  <unfinished ...>
[pid 21203] futex(0x133e7d8, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid 21201] fstat(17,  <unfinished ...>
[pid 21203] <... futex resumed> )       = 0
[pid 21201] <... fstat resumed> {st_mode=S_IFREG|0664, st_size=1074, ...}) = 0
[pid 21203] sched_yield( <unfinished ...>
[pid 21184] <... epoll_pwait resumed> {}, 128, 0, NULL) = 0
[pid 21203] <... sched_yield resumed> ) = 0
[pid 21201] read(17,  <unfinished ...>
[pid 21203] futex(0x133e7d8, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid 21201] <... read resumed> "-----BEGIN CERTIFICATE-----\nMIIC"..., 1586) = 1074
[pid 21203] <... futex resumed> )       = 0
[pid 21201] read(17,  <unfinished ...>
[pid 21184] nanosleep({0, 3000},  <unfinished ...>
[pid 21201] <... read resumed> "", 512) = 0
[pid 21189] sched_yield( <unfinished ...>
[pid 21201] close(17 <unfinished ...>
[pid 21203] lstat("/volume1/KUNDEN_1/SALT_Front Office",  <unfinished ...>
[pid 21201] <... close resumed> )       = 0
[pid 21203] <... lstat resumed> {st_mode=S_IFDIR|0777, st_size=1274, ...}) = 0
[pid 21201] openat(AT_FDCWD, "/usr/local/syncthing/var/https-key.pem", O_RDONLY|O_CLOEXEC <unfinished ...>
[pid 21189] <... sched_yield resumed> ) = 0
[pid 21184] <... nanosleep resumed> NULL) = 0
[pid 21203] futex(0x133e7d8, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid 21201] <... openat resumed> )      = 17
[pid 21203] <... futex resumed> )       = 0
[pid 21201] epoll_ctl(4, EPOLL_CTL_ADD, 17, {EPOLLIN|EPOLLOUT|EPOLLRDHUP|EPOLLET, {u32=4080893584, u64=140157453696656}} <unfinished ...>
[pid 21189] futex(0x133e7d8, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
[pid 21201] <... epoll_ctl resumed> )   = -1 EPERM (Operation not permitted)
[pid 21189] <... futex resumed> )       = -1 EAGAIN (Resource temporarily unavailable)
[pid 21201] epoll_ctl(4, EPOLL_CTL_DEL, 17, {0, {u32=0, u64=0}} <unfinished ...>
[pid 21189] futex(0x133e7d8, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid 21203] lstat("/volume1/KUNDEN_1/SALT_KVA",  <unfinished ...>
[pid 21201] <... epoll_ctl resumed> )   = -1 EPERM (Operation not permitted)
[pid 21203] <... lstat resumed> {st_mode=S_IFDIR|0777, st_size=254, ...}) = 0
[pid 21201] fstat(17,  <unfinished ...>
[pid 21189] <... futex resumed> )       = 0
[pid 21201] <... fstat resumed> {st_mode=S_IFREG|0600, st_size=1675, ...}) = 0
[pid 21189] sched_yield( <unfinished ...>
[pid 21201] read(17,  <unfinished ...>
[pid 21189] <... sched_yield resumed> ) = 0
[pid 21201] <... read resumed> "-----BEGIN RSA PRIVATE KEY-----\n"..., 2187) = 1675
[pid 21203] sched_yield( <unfinished ...>
[pid 21201] read(17,  <unfinished ...>
[pid 21203] <... sched_yield resumed> ) = 0
[pid 21201] <... read resumed> "", 512) = 0
[pid 21189] futex(0x133e7d8, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid 21201] close(17 <unfinished ...>
[pid 21203] lstat("/volume1/KUNDEN_1/DCBK_Office",  <unfinished ...>
[pid 21201] <... close resumed> )       = 0
[pid 21203] <... lstat resumed> {st_mode=S_IFDIR|0777, st_size=590, ...}) = 0
[pid 21189] <... futex resumed> )       = 0
[pid 21184] write(1, "[2H2JG] 2018/12/06 08:51:50.8072"..., 161 <unfinished ...>
[pid 21175] write(1, "[2H2JG] 2018/12/06 08:51:50.8065"..., 155 <unfinished ...>
[pid 21203] sched_yield( <unfinished ...>
[pid 21184] <... write resumed> )       = 161
[pid 21203] <... sched_yield resumed> ) = 0
[pid 21189] geteuid( <unfinished ...>
[pid 21203] futex(0x133e7d8, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid 21175] <... write resumed> )       = 155
[pid 21203] <... futex resumed> )       = 0
[pid 21175] read(7,  <unfinished ...>
[pid 21189] <... geteuid resumed> )     = 114670
[pid 21184] sched_yield( <unfinished ...>
[pid 21175] <... read resumed> "[2H2JG] 2018/12/06 08:51:50.8072"..., 4096) = 161
[pid 21184] <... sched_yield resumed> ) = 0
[pid 21170] <... nanosleep resumed> NULL) = 0
[pid 21189] futex(0x133e7d8, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid 21184] futex(0x133e7d8, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
[pid 21189] <... futex resumed> )       = 0
[pid 21184] <... futex resumed> )       = -1 EAGAIN (Resource temporarily unavailable)
[pid 21175] write(1, "[2H2JG] 2018/12/06 08:51:50.8072"..., 161 <unfinished ...>
[pid 21203] lstat("/volume1/KUNDEN_1/DRUCKDATEN_JG_2018",  <unfinished ...>
[pid 21184] sched_yield( <unfinished ...>
[pid 21203] <... lstat resumed> {st_mode=S_IFDIR|0777, st_size=170, ...}) = 0
[pid 21189] write(1, "[2H2JG] 2018/12/06 08:51:50.8079"..., 153 <unfinished ...>
[pid 21184] <... sched_yield resumed> ) = 0
[pid 21189] <... write resumed> )       = 153
[pid 21203] futex(0x133e7d8, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid 21189] futex(0x131f120, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid 21203] <... futex resumed> )       = 0
[pid 21189] <... futex resumed> )       = 1
[pid 21187] <... futex resumed> )       = 0
[pid 21184] futex(0x133e7d8, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
[pid 21187] futex(0xc000578140, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
[pid 21201] socket(PF_INET6, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, IPPROTO_IP <unfinished ...>
[pid 21189] newfstatat(AT_FDCWD, "/usr/local/syncthing/var",  <unfinished ...>
[pid 21201] <... socket resumed> )      = 17
[pid 21203] lstat("/volume1/KUNDEN_1/DATENSCHUTZFORMULARE",  <unfinished ...>
[pid 21201] setsockopt(17, SOL_IPV6, IPV6_V6ONLY, [0], 4 <unfinished ...>
[pid 21203] <... lstat resumed> {st_mode=S_IFDIR|0777, st_size=1098, ...}) = 0
[pid 21201] <... setsockopt resumed> )  = 0
[pid 21189] <... newfstatat resumed> {st_mode=S_IFDIR|0700, st_size=310, ...}, 0) = 0
[pid 21201] setsockopt(17, SOL_SOCKET, SO_BROADCAST, [1], 4 <unfinished ...>
[pid 21189] openat(AT_FDCWD, "/usr/local/syncthing/var", O_RDONLY|O_CLOEXEC <unfinished ...>
[pid 21201] <... setsockopt resumed> )  = 0
[pid 21184] <... futex resumed> )       = -1 EAGAIN (Resource temporarily unavailable)
[pid 21201] setsockopt(17, SOL_SOCKET, SO_REUSEADDR, [1], 4 <unfinished ...>
[pid 21203] lstat("/volume1/KUNDEN_1/KUG_2018",  <unfinished ...>
[pid 21201] <... setsockopt resumed> )  = 0
[pid 21203] <... lstat resumed> {st_mode=S_IFDIR|0777, st_size=266, ...}) = 0
[pid 21201] bind(17, {sa_family=AF_INET6, sin6_port=htons(8384), inet_pton(AF_INET6, "::", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, 28 <unfinished ...>
[pid 21189] <... openat resumed> )      = 18
[pid 21201] <... bind resumed> )        = 0
[pid 21189] epoll_ctl(4, EPOLL_CTL_ADD, 18, {EPOLLIN|EPOLLOUT|EPOLLRDHUP|EPOLLET, {u32=4080893584, u64=140157453696656}} <unfinished ...>
[pid 21201] listen(17, 65535 <unfinished ...>
[pid 21189] <... epoll_ctl resumed> )   = -1 EPERM (Operation not permitted)
[pid 21184] futex(0x133e7d8, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid 21201] <... listen resumed> )      = 0
[pid 21203] lstat("/volume1/KUNDEN_1/AIRBNB",  <unfinished ...>
[pid 21201] epoll_ctl(4, EPOLL_CTL_ADD, 17, {EPOLLIN|EPOLLOUT|EPOLLRDHUP|EPOLLET, {u32=4080893376, u64=140157453696448}} <unfinished ...>
[pid 21203] <... lstat resumed> {st_mode=S_IFDIR|0777, st_size=216, ...}) = 0
[pid 21201] <... epoll_ctl resumed> )   = 0
[pid 21189] epoll_ctl(4, EPOLL_CTL_DEL, 18, {0, {u32=0, u64=0}} <unfinished ...>
[pid 21201] getsockname(17,  <unfinished ...>
[pid 21189] <... epoll_ctl resumed> )   = -1 EPERM (Operation not permitted)
[pid 21201] <... getsockname resumed> {sa_family=AF_INET6, sin6_port=htons(8384), inet_pton(AF_INET6, "::", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, [28]) = 0
[pid 21189] getdents64(18,  <unfinished ...>
[pid 21184] <... futex resumed> )       = 0
[pid 21175] <... write resumed> )       = 161
[pid 21203] lstat("/volume1/KUNDEN_1/FOTOS_Norman",  <unfinished ...>
[pid 21175] read(7,  <unfinished ...>
[pid 21203] <... lstat resumed> {st_mode=S_IFDIR|0777, st_size=230, ...}) = 0
[pid 21175] <... read resumed> "[2H2JG] 2018/12/06 08:51:50.8079"..., 4096) = 153
[pid 21170] nanosleep({0, 20000},  <unfinished ...>
[pid 21189] <... getdents64 resumed> /* 14 entries */, 8192) = 504
[pid 21184] futex(0xc000578140, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid 21201] openat(AT_FDCWD, "/usr/local/syncthing/var/csrftokens.txt", O_RDONLY|O_CLOEXEC <unfinished ...>
[pid 21189] getdents64(18,  <unfinished ...>
[pid 21187] <... futex resumed> )       = 0
[pid 21201] <... openat resumed> )      = 19
[pid 21189] <... getdents64 resumed> /* 0 entries */, 8192) = 0
[pid 21201] epoll_ctl(4, EPOLL_CTL_ADD, 19, {EPOLLIN|EPOLLOUT|EPOLLRDHUP|EPOLLET, {u32=4080893584, u64=140157453696656}} <unfinished ...>
[pid 21187] epoll_pwait(4,  <unfinished ...>
[pid 21203] lstat("/volume1/KUNDEN_1/Alex",  <unfinished ...>
[pid 21201] <... epoll_ctl resumed> )   = -1 EPERM (Operation not permitted)
[pid 21203] <... lstat resumed> {st_mode=S_IFDIR|0777, st_size=64, ...}) = 0
[pid 21201] epoll_ctl(4, EPOLL_CTL_DEL, 19, {0, {u32=0, u64=0}} <unfinished ...>
[pid 21189] close(18 <unfinished ...>
[pid 21201] <... epoll_ctl resumed> )   = -1 EPERM (Operation not permitted)
[pid 21189] <... close resumed> )       = 0
[pid 21187] <... epoll_pwait resumed> {}, 128, 0, NULL) = 0
[pid 21201] read(19,  <unfinished ...>
[pid 21184] <... futex resumed> )       = 1
[pid 21175] write(1, "[2H2JG] 2018/12/06 08:51:50.8079"..., 153 <unfinished ...>
[pid 21184] futex(0x131f120, FUTEX_WAIT_PRIVATE, 0, {29, 981178156} <unfinished ...>
[pid 21203] lstat("/volume1/KUNDEN_1/IT_Daten SALT.sparseimage",  <unfinished ...>
[pid 21189] write(1, "[2H2JG] 2018/12/06 08:51:50.8090"..., 142 <unfinished ...>
[pid 21203] <... lstat resumed> {st_mode=S_IFREG|0777, st_size=7345404, ...}) = 0
[pid 21201] <... read resumed> "ANEPVroCsR3EPHofdSVwGXAHsWKJgche"..., 4096) = 132
[pid 21189] <... write resumed> )       = 142
[pid 21187] epoll_pwait(4,  <unfinished ...>
[pid 21201] read(19,  <unfinished ...>
[pid 21189] lstat("/usr/local/syncthing/var/config.xml.v28",  <unfinished ...>
[pid 21201] <... read resumed> "", 3964) = 0
[pid 21187] <... epoll_pwait resumed> {}, 128, 0, NULL) = 0
[pid 21201] close(19 <unfinished ...>
[pid 21203] lstat("/volume1/KUNDEN_1/AUSWAHL",  <unfinished ...>
[pid 21201] <... close resumed> )       = 0
[pid 21203] <... lstat resumed> {st_mode=S_IFDIR|0777, st_size=0, ...}) = 0
[pid 21189] <... lstat resumed> {st_mode=S_IFREG|0600, st_size=4401, ...}) = 0
[pid 21187] futex(0x131f020, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid 21203] sched_yield( <unfinished ...>
[pid 21202] <... futex resumed> )       = 0
[pid 21203] <... sched_yield resumed> ) = 0
[pid 21202] futex(0xc000050f40, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
[pid 21203] futex(0x133e7d8, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid 21189] write(1, "[2H2JG] 2018/12/06 08:51:50.8093"..., 141 <unfinished ...>
[pid 21203] <... futex resumed> )       = 0
[pid 21189] <... write resumed> )       = 141
[pid 21203] sched_yield( <unfinished ...>
[pid 21187] <... futex resumed> )       = 1
[pid 21203] <... sched_yield resumed> ) = 0
[pid 21201] socket(PF_NETLINK, SOCK_RAW, 0 <unfinished ...>
[pid 21203] futex(0x133e7d8, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid 21201] <... socket resumed> )      = 18
[pid 21203] <... futex resumed> )       = 0
[pid 21201] bind(18, {sa_family=AF_NETLINK, pid=0, groups=00000000}, 12 <unfinished ...>
[pid 21189] lstat("/usr/local/syncthing/var/backup-of-v0.8",  <unfinished ...>
[pid 21201] <... bind resumed> )        = 0
[pid 21187] write(1, "[2H2JG] 2018/12/06 08:51:50.8095"..., 83 <unfinished ...>
[pid 21201] sendto(18, "\21\0\0\0\26\0\1\3\1\0\0\0\0\0\0\0\0", 17, 0, {sa_family=AF_NETLINK, pid=0, groups=00000000}, 12 <unfinished ...>
[pid 21189] <... lstat resumed> 0xc000099078) = -1 ENOENT (No such file or directory)
[pid 21203] lstat("/volume1/KUNDEN_1/MICHELIN_Aussenwerbung.pdf",  <unfinished ...>
[pid 21201] <... sendto resumed> )      = 17
[pid 21203] <... lstat resumed> {st_mode=S_IFREG|0777, st_size=398685, ...}) = 0
[pid 21201] recvfrom(18,  <unfinished ...>
[pid 21187] <... write resumed> )       = 83
[pid 21189] futex(0xc000050f40, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid 21201] <... recvfrom resumed> "D\0\0\0\24\0\2\0\1\0\0\0\276R\0\0\2\10\200\376\1\0\0\0\10\0\1\0\177\0\0\1"..., 4096, 0, {sa_family=AF_NETLINK, pid=0, groups=00000000}, [12]) = 300
[pid 21202] <... futex resumed> )       = 0
[pid 21201] getsockname(18,  <unfinished ...>
[pid 21202] epoll_pwait(4,  <unfinished ...>
[pid 21201] <... getsockname resumed> {sa_family=AF_NETLINK, pid=21182, groups=00000000}, [12]) = 0
[pid 21202] <... epoll_pwait resumed> {}, 128, 0, NULL) = 0
[pid 21201] getsockname(18,  <unfinished ...>
[pid 21189] <... futex resumed> )       = 1
[pid 21201] <... getsockname resumed> {sa_family=AF_NETLINK, pid=21182, groups=00000000}, [12]) = 0
[pid 21189] futex(0xc0005784c0, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
[pid 21203] inotify_add_watch(13, "/volume1/KUNDEN_1/AUSWAHL", IN_MODIFY|IN_MOVED_FROM|IN_MOVED_TO|IN_CREATE|IN_DELETE|IN_DELETE_SELF|IN_MOVE_SELF <unfinished ...>
[pid 21202] sched_yield( <unfinished ...>
[pid 21201] getsockname(18,  <unfinished ...>
[pid 21203] <... inotify_add_watch resumed> ) = 2
[pid 21202] <... sched_yield resumed> ) = 0
[pid 21203] openat(AT_FDCWD, "/volume1/KUNDEN_1/AUSWAHL", O_RDONLY|O_CLOEXEC <unfinished ...>
[pid 21202] futex(0x131f000, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
[pid 21203] <... openat resumed> )      = 19
[pid 21201] <... getsockname resumed> {sa_family=AF_NETLINK, pid=21182, groups=00000000}, [12]) = 0
[pid 21203] epoll_ctl(4, EPOLL_CTL_ADD, 19, {EPOLLIN|EPOLLOUT|EPOLLRDHUP|EPOLLET, {u32=4080893584, u64=140157453696656}} <unfinished ...>
[pid 21201] getsockname(18,  <unfinished ...>
[pid 21203] <... epoll_ctl resumed> )   = -1 EPERM (Operation not permitted)
[pid 21201] <... getsockname resumed> {sa_family=AF_NETLINK, pid=21182, groups=00000000}, [12]) = 0
[pid 21203] epoll_ctl(4, EPOLL_CTL_DEL, 19, {0, {u32=0, u64=0}} <unfinished ...>
[pid 21201] recvfrom(18,  <unfinished ...>
[pid 21203] <... epoll_ctl resumed> )   = -1 EPERM (Operation not permitted)
[pid 21201] <... recvfrom resumed> "@\0\0\0\24\0\2\0\1\0\0\0\276R\0\0\n\200\200\376\1\0\0\0\24\0\1\0\0\0\0\0"..., 4096, 0, {sa_family=AF_NETLINK, pid=0, groups=00000000}, [12]) = 192
[pid 21203] getdents64(19,  <unfinished ...>
[pid 21201] getsockname(18,  <unfinished ...>
[pid 21187] futex(0x131f020, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid 21203] <... getdents64 resumed> /* 2 entries */, 8192) = 48
[pid 21201] <... getsockname resumed> {sa_family=AF_NETLINK, pid=21182, groups=00000000}, [12]) = 0
[pid 21203] getdents64(19,  <unfinished ...>
[pid 21201] getsockname(18,  <unfinished ...>
[pid 21203] <... getdents64 resumed> /* 0 entries */, 8192) = 0
[pid 21201] <... getsockname resumed> {sa_family=AF_NETLINK, pid=21182, groups=00000000}, [12]) = 0
[pid 21203] close(19 <unfinished ...>
[pid 21201] getsockname(18,  <unfinished ...>
[pid 21203] <... close resumed> )       = 0
[pid 21201] <... getsockname resumed> {sa_family=AF_NETLINK, pid=21182, groups=00000000}, [12]) = 0
[pid 21203] inotify_add_watch(13, "/volume1/KUNDEN_1/Alex", IN_MODIFY|IN_MOVED_FROM|IN_MOVED_TO|IN_CREATE|IN_DELETE|IN_DELETE_SELF|IN_MOVE_SELF <unfinished ...>
[pid 21201] recvfrom(18,  <unfinished ...>
[pid 21203] <... inotify_add_watch resumed> ) = 3
[pid 21201] <... recvfrom resumed> "\24\0\0\0\3\0\2\0\1\0\0\0\276R\0\0\0\0\0\0", 4096, 0, {sa_family=AF_NETLINK, pid=0, groups=00000000}, [12]) = 20
[pid 21203] openat(AT_FDCWD, "/volume1/KUNDEN_1/Alex", O_RDONLY|O_CLOEXEC <unfinished ...>
[pid 21201] getsockname(18,  <unfinished ...>
[pid 21203] <... openat resumed> )      = 19
[pid 21201] <... getsockname resumed> {sa_family=AF_NETLINK, pid=21182, groups=00000000}, [12]) = 0
[pid 21203] epoll_ctl(4, EPOLL_CTL_ADD, 19, {EPOLLIN|EPOLLOUT|EPOLLRDHUP|EPOLLET, {u32=4080893584, u64=140157453696656}} <unfinished ...>
[pid 21201] close(18 <unfinished ...>

And later when there is less noise:

[pid 21218] inotify_add_watch(13, "/volume1/KUNDEN_1/SALT_Front Office/Praktikanten/Mahnungen/Kleinkunden", IN_MODIFY|IN_MOVED_FROM|IN_MOVED_TO|IN_CREATE|IN_DELETE|IN_DELETE_SELF|IN_MOVE_SELF) = 9518
[pid 21218] openat(AT_FDCWD, "/volume1/KUNDEN_1/SALT_Front Office/Praktikanten/Mahnungen/Kleinkunden", O_RDONLY|O_CLOEXEC) = 106
[pid 21218] epoll_ctl(4, EPOLL_CTL_ADD, 106, {EPOLLIN|EPOLLOUT|EPOLLRDHUP|EPOLLET, {u32=4080892960, u64=140157453696032}}) = -1 EPERM (Operation not permitted)
[pid 21218] epoll_ctl(4, EPOLL_CTL_DEL, 106, {0, {u32=0, u64=0}}) = -1 EPERM (Operation not permitted)
[pid 21218] getdents64(106, /* 22 entries */, 8192) = 992
[pid 21218] getdents64(106, /* 0 entries */, 8192) = 0
[pid 21218] close(106)                  = 0

#32

OK, the issue - as correctly identified by @AudriusButkevicius and @bigbear2nd - seems to be with the POSIX permissions of the root folder. Creating a folder one level below Synology’s shared folder solves the issue as long as owner is sc-syncthing with rwx permissions.


(Audrius Butkevicius) #33

It’s a bit sad that so much time was wasted when the first reply to the post essentially explained the issue. Sure, your NAS uses ACLs and what not, but the kernel still uses posix permissions, regardless of what your NAS does.


#34

I’m very sorry. Thanks for your patience.


#35

I did some more testing and the issue is not as easy and straightforward as it seems. inotify fails on some folders and succeeds on others. Permissions are 100% identical and the syncthing user is not the owner or group. So there is something weird going on that is probably not in the scope of the Syncthing developers.

I just wanted to feedback that it is probably not an issue of POSIX permissions missing and that ACLs work in principle fine. As soon as I found out more I will post the root cause of the issue here.

Thanks for your time and effort. Much appreciated.


#36

So the result of my testing and debugging is as follows:

Syncthing and inotifywait work on some dirs (e. g. /volume1/KUNDEN_1/A ) and not on others (e. g. /volume1/KUNDEN_1/B ), the dirs having the exact same ownership and permissions (ACL and POSIX). They NEVER fail on the root shared folder /volume1/KUNDEN_1 even if it is owned by root and has all ACL deleted (so the syncthing user should not have any permissions at all)! That makes no sense to me and is maybe caused by a faulty inotify API on Synology NAS. Their support has of course nothing to contribute.

I now just run a script every night to change ownership of dirs via Task Manager. It is not necessary to change permissions or group. Just ownership is sufficient, even if the owner has 0 permissions.

Hope it helps someone else in the same situation.

Thanks you all for help, input and patience in this matter, much appreciated.