Mac Finder file duplication leads to incoherent FCE events

[seiman]

Using the duplicate function of the finder (⌘+d) leads to the fce events afpd[43] {fce_api.c:533} (debug:FCE): register_fce(path: /media/share/P00002315572 Kopie.jpg, event: FCE_FILE_CREATE) afpd[43] {fce_api.c:533} (debug:FCE): register_fce(path: /media/share/P00002315572 Kopie.jpg, event: FCE_FILE_DELETE)

We assume, that the file is first being created, then deleted, then created again and modified, but only events for the first two operations are being created.

Tested on MacOs 10.12.6 and 10.14.5

[rdmark]

I can observe the same in the latest main code, macOS Ventura.

Further down in the log I get this, where afpd detects a file create request for the same file:

Apr 08 13:37:00 rasp32 afpd[8577]: cname_mtouname('afpd-icon copy.bmp',did:2) {demangled:'afpd-icon copy.bmp', fileid:0}
Apr 08 13:37:00 rasp32 afpd[8577]: cname('/home/dmark/afp-data'): {node: 'afpd-icon copy.bmp}
Apr 08 13:37:00 rasp32 afpd[8577]: of_stat('/home/dmark/afp-data/afpd-icon copy.bmp': No such file or directory)
Apr 08 13:37:00 rasp32 afpd[8577]: cname('/home/dmark/afp-data'): {leave-cnode ENOENT (probably create request): 'afpd-icon copy.bmp'}
Apr 08 13:37:00 rasp32 afpd[8577]: cname('/home/dmark/afp-data') {end: curdir:'/home/dmark/afp-data', path:'afpd-icon copy.bmp'}
Apr 08 13:37:00 rasp32 afpd[8577]: getfildirparams(vid:1, did:2, f/d:e93f/a33f) {cwdid:2, cwd: /home/dmark/afp-data, name:'afpd-icon copy.bmp'}
Apr 08 13:37:00 rasp32 afpd[8577]: ==> Finished AFP command: AFP_GETFLDRPARAM -> AFPERR_NOOBJ

But FCE doesn't seem to be aware according to the logs.

[rdmark]

@seiman Were you attempting to address this issue with your PRs in https://github.com/Netatalk/netatalk/pull/98 and https://github.com/Netatalk/netatalk/pull/99 by any chance?

[rdmark]

Unfortunately the improvements in https://github.com/Netatalk/netatalk/pull/849 didn't actually address this particular issue (although they improved other scenarios.)

[rdmark]

For the record: There is an easy way to observe this, by using the fce sample app:

$ ./build/bin/misc/fce -h localhost
listener: waiting to recvfrom...
FCE Start
ID: 1, Event: FCE_LOGIN, Path: 
ID: 2, Event: FCE_LOGOUT, Path: 
[...]
ID: 3, Event: FCE_FILE_MOVE, Path: /srv/afpad1/index2.html
ID: 4, Event: FCE_FILE_CREATE, Path: /srv/afpad1/index2 copy.html
ID: 5, Event: FCE_FILE_DELETE, Path: /srv/afpad1/index2 copy.html

[rdmark]

A fix is prepared in https://github.com/Netatalk/netatalk/pull/2027

The problem was due to a missing event registration in afp_copyfile()

Now the FCE event log looks something like this with macOS clients.

FCE Start
ID: 1, Event: FCE_LOGIN, pid: 146174, user: dmark, Path: 
ID: 2, Event: FCE_FILE_CREATE, pid: 146174, user: dmark, Path: /srv/afpme/uams_guest copy.c
ID: 3, Event: FCE_FILE_DELETE, pid: 146174, user: dmark, Path: /srv/afpme/uams_guest copy.c
ID: 4, Event: FCE_FILE_CREATE, pid: 146174, user: dmark, Path: /srv/afpme/uams_guest copy.c

Interestingly, the create->delete->create roundtrip does not occur with f.e. OS9 AppleShare clients.