this is similar to issue# 263624 which had been marked as fixed - but it doesn't seem to be the case. System: FreeBSD 13.2-RELEASE here - netatalk3-3.1.14,1 - zfs file systems. Example of share definition in afp.conf: [Courant] path = /Pool/Global/Storage/Courant valid users = @users file perm = 0660 directory perm = 0770 seeing thousands of entries such as those below, in /var/log/netatalk.log - sometimes pointing at files and sometimes at directories. As a workaround, trying to revert to 3.1.12 - can someone recommend a way to do that on 13.2-RELEASE ? Trying to install older version that are in /var/cache/pkg result in 'wrong architecture' errors. Cedric Tineo Apr 27 10:15:40.374288 afpd[29935] {ad_open.c:818} (error:ad): ad_header_read_ea("/Pool/Global/Storage/Courant"): invalid metadata EA this is now being treated as a fatal error. if you see this log entry, please file a bug ticket with your upstream vendor and attach the generated core file. Apr 27 10:15:40.374342 afpd[29935] {ad_open.c:1280} (error:ad): ad_open_hf_ea: unexpected: Invalid argument Apr 27 10:15:50.366800 afpd[29935] {ad_open.c:818} (error:ad): ad_header_read_ea("/Pool/Global/Storage/Archives/."): invalid metadata EA this is now being treated as a fatal error. if you see this log entry, please file a bug ticket with your upstream vendor and attach the generated core file. Apr 27 10:15:50.367632 afpd[29935] {ad_open.c:818} (error:ad): ad_header_read_ea("/Pool/Global/Storage/Courant"): invalid metadata EA this is now being treated as a fatal error. if you see this log entry, please file a bug ticket with your upstream vendor and attach the generated core file. Apr 27 10:15:50.367686 afpd[29935] {ad_open.c:1280} (error:ad): ad_open_hf_ea: unexpected: Invalid argument Apr 27 10:15:50.374197 afpd[29935] {ad_open.c:818} (error:ad): ad_header_read_ea("/Pool/Global/Storage/Archives"): invalid metadata EA this is now being treated as a fatal error. if you see this log entry, please file a bug ticket with your upstream vendor and attach the generated core file. Apr 27 10:15:50.374249 afpd[29935] {ad_open.c:1280} (error:ad): ad_open_hf_ea: unexpected: Invalid argument
*** Bug 271096 has been marked as a duplicate of this bug. ***
Created attachment 241796 [details] Add more debugging
Can you try with this attached patch (rebuild netatalk with it) and then post the new logs along with the full afp.conf?
FYI, just copy this file into net/netatalk3/files and rebuild/reinstall netatalk3.
Comment on attachment 241796 [details] Add more debugging so, added a text file with the content in your attachement - in /usr/ports/net/netatalk3/files/ with filename - patch-libatalk_adouble_ad_open.c - same permissions as other files in the foler ran: service netatalk stop pkg remove netatalk3 make config-recursive # not sure if that step was needed, left all options at their default make install clean # full output of that command was preserved, I can send it upon request service netatalk start here are the kind of things that show up in netatalk.log - i can send the full file or more exceprts upon request. Regards, Cedric Apr 28 13:55:07.973840 afpd[15783] {ad_open.c:826} (error:ad): ad_header_read_ea("/Pool/Global/Backup/Backup-Vagabond/Vagabond-M1.sparsebundle/com.apple.TimeMachine.MachineID.plist"): invalid metadata EA this is now being treated as a fatal error. if you see this log entry, please file a bug ticket with your upstream vendor and attach the generated core file (nentries = 8, ADEID_NUM_EA = 8 ADEID_FINDERI = 210b103a, ADEID_FILEDATESI = 210b1122, ADEID_AFPFILEI = 210b1132, ADEID_PRIVDEV = 0, ADEID_PRIVINO = 0, ADEID_PRIVSYN = 210b1146, ADEID_PRIVID = 210b114e). Apr 28 13:55:07.978329 afpd[15783] {ad_open.c:826} (error:ad): ad_header_read_ea("/Pool/Global/Backup/Backup-Vagabond/Vagabond-M1.sparsebundle/com.apple.TimeMachine.MachineID.bckup"): invalid metadata EA this is now being treated as a fatal error. if you see this log entry, please file a bug ticket with your upstream vendor and attach the generated core file (nentries = 8, ADEID_NUM_EA = 8 ADEID_FINDERI = 210b103a, ADEID_FILEDATESI = 210b1122, ADEID_AFPFILEI = 210b1132, ADEID_PRIVDEV = 0, ADEID_PRIVINO = 0, ADEID_PRIVSYN = 210b1146, ADEID_PRIVID = 210b114e). Apr 28 13:55:07.979888 afpd[15783] {ad_open.c:826} (error:ad): ad_header_read_ea("/Pool/Global/Backup/Backup-Vagabond/Vagabond-M1.sparsebundle/com.apple.TimeMachine.MachineID.bckup"): invalid metadata EA this is now being treated as a fatal error. if you see this log entry, please file a bug ticket with your upstream vendor and attach the generated core file (nentries = 8, ADEID_NUM_EA = 8 ADEID_FINDERI = 341e578a, ADEID_FILEDATESI = 341e5872, ADEID_AFPFILEI = 341e5882, ADEID_PRIVDEV = 0, ADEID_PRIVINO = 0, ADEID_PRIVSYN = 341e5896, ADEID_PRIVID = 341e589e). Apr 28 13:55:07.979965 afpd[15783] {ad_open.c:1288} (error:ad): ad_open_hf_ea: unexpected: Invalid argument Apr 28 13:55:07.979998 afpd[15783] {fork.c:423} (error:AFPDaemon): afp_openfork(com.apple.TimeMachine.MachineID.bckup): ad_open: Invalid argument Apr 28 13:55:07.980799 afpd[15783] {ad_open.c:826} (error:ad): ad_header_read_ea("/Pool/Global/Backup/Backup-Vagabond/Vagabond-M1.sparsebundle/com.apple.TimeMachine.MachineID.bckup"): invalid metadata EA this is now being treated as a fatal error. if you see this log entry, please file a bug ticket with your upstream vendor and attach the generated core file (nentries = 8, ADEID_NUM_EA = 8 ADEID_FINDERI = 341e578a, ADEID_FILEDATESI = 341e5872, ADEID_AFPFILEI = 341e5882, ADEID_PRIVDEV = 0, ADEID_PRIVINO = 0, ADEID_PRIVSYN = 341e5896, ADEID_PRIVID = 341e589e). Apr 28 13:55:07.980844 afpd[15783] {ad_open.c:1288} (error:ad): ad_open_hf_ea: unexpected: Invalid argument Apr 28 13:55:07.980856 afpd[15783] {fork.c:423} (error:AFPDaemon): afp_openfork(com.apple.TimeMachine.MachineID.bckup): ad_open: Invalid argument Apr 28 13:55:08.068679 afpd[15783] {ad_open.c:826} (error:ad): ad_header_read_ea("/Pool/Global/Backup/Backup-Vagabond/Vagabond-M1.sparsebundle/com.apple.TimeMachine.MachineID.plist"): invalid metadata EA this is now being treated as a fatal error. if you see this log entry, please file a bug ticket with your upstream vendor and attach the generated core file (nentries = 8, ADEID_NUM_EA = 8 ADEID_FINDERI = 210b103a, ADEID_FILEDATESI = 210b1122, ADEID_AFPFILEI = 210b1132, ADEID_PRIVDEV = 0, ADEID_PRIVINO = 0, ADEID_PRIVSYN = 210b1146, ADEID_PRIVID = 210b114e). Apr 28 13:55:08.069680 afpd[15783] {ad_open.c:826} (error:ad): ad_header_read_ea("/Pool/Global/Backup/Backup-Vagabond/Vagabond-M1.sparsebundle/com.apple.TimeMachine.MachineID.plist"): invalid metadata EA this is now being treated as a fatal error. if you see this log entry, please file a bug ticket with your upstream vendor and attach the generated core file (nentries = 8, ADEID_NUM_EA = 8 ADEID_FINDERI = 341e578a, ADEID_FILEDATESI = 341e5872, ADEID_AFPFILEI = 341e5882, ADEID_PRIVDEV = 0, ADEID_PRIVINO = 0, ADEID_PRIVSYN = 341e5896, ADEID_PRIVID = 341e589e). Apr 28 13:55:08.071503 afpd[15783] {ad_open.c:826} (error:ad): ad_header_read_ea("/Pool/Global/Backup/Backup-Vagabond/Vagabond-M1.sparsebundle/com.apple.TimeMachine.MachineID.plist"): invalid metadata EA this is now being treated as a fatal error. if you see this log entry, please file a bug ticket with your upstream vendor and attach the generated core file (nentries = 8, ADEID_NUM_EA = 8 ADEID_FINDERI = 210b103a, ADEID_FILEDATESI = 210b1122, ADEID_AFPFILEI = 210b1132, ADEID_PRIVDEV = 0, ADEID_PRIVINO = 0, ADEID_PRIVSYN = 210b1146, ADEID_PRIVID = 210b114e). Apr 28 13:55:08.073463 afpd[15783] {ad_open.c:826} (error:ad): ad_header_read_ea("/Pool/Global/Backup/Backup-Vagabond/Vagabond-M1.sparsebundle/Info.plist"): invalid metadata EA this is now being treated as a fatal error. if you see this log entry, please file a bug ticket with your upstream vendor and attach the generated core file (nentries = 8, ADEID_NUM_EA = 8 ADEID_FINDERI = 210b103a, ADEID_FILEDATESI = 210b1122, ADEID_AFPFILEI = 210b1132, ADEID_PRIVDEV = 0, ADEID_PRIVINO = 0, ADEID_PRIVSYN = 210b1146, ADEID_PRIVID = 210b114e). Apr 28 13:55:08.074875 afpd[15783] {ad_open.c:826} (error:ad): ad_header_read_ea("/Pool/Global/Backup/Backup-Vagabond/Vagabond-M1.sparsebundle/Info.plist"): invalid metadata EA this is now being treated as a fatal error. if you see this log entry, please file a bug ticket with your upstream vendor and attach the generated core file (nentries = 8, ADEID_NUM_EA = 8 ADEID_FINDERI = 341e578a, ADEID_FILEDATESI = 341e5872, ADEID_AFPFILEI = 341e5882, ADEID_PRIVDEV = 0, ADEID_PRIVINO = 0, ADEID_PRIVSYN = 341e5896, ADEID_PRIVID = 341e589e). Apr 28 13:55:08.077012 afpd[15783] {ad_open.c:826} (error:ad): ad_header_read_ea("/Pool/Global/Backup/Backup-Vagabond/Vagabond-M1.sparsebundle/token"): invalid metadata EA this is now being treated as a fatal error. if you see this log entry, please file a bug ticket with your upstream vendor and attach the generated core file (nentries = 8, ADEID_NUM_EA = 8 ADEID_FINDERI = 210b103a, ADEID_FILEDATESI = 210b1122, ADEID_AFPFILEI = 210b1132, ADEID_PRIVDEV = 0, ADEID_PRIVINO = 0, ADEID_PRIVSYN = 210b1146, ADEID_PRIVID = 210b114e). Apr 28 13:55:08.078018 afpd[15783] {ad_open.c:826} (error:ad): ad_header_read_ea("/Pool/Global/Backup/Backup-Vagabond/Vagabond-M1.sparsebundle/token"): invalid metadata EA this is now being treated as a fatal error. if you see this log entry, please file a bug ticket with your upstream vendor and attach the generated core file (nentries = 8, ADEID_NUM_EA = 8 ADEID_FINDERI = 341e5e8a, ADEID_FILEDATESI = 341e5f72, ADEID_AFPFILEI = 341e5f82, ADEID_PRIVDEV = 0, ADEID_PRIVINO = 0, ADEID_PRIVSYN = 341e5f96, ADEID_PRIVID = 341e5f9e). Apr 28 13:55:08.079835 afpd[15783] {ad_open.c:826} (error:ad): ad_header_read_ea("/Pool/Global/Backup/Backup-Vagabond/Vagabond-M1.sparsebundle/token"): invalid metadata EA this is now being treated as a fatal error. if you see this log entry, please file a bug ticket with your upstream vendor and attach the generated core file (nentries = 8, ADEID_NUM_EA = 8 ADEID_FINDERI = 210b103a, ADEID_FILEDATESI = 210b1122, ADEID_AFPFILEI = 210b1132, ADEID_PRIVDEV = 0, ADEID_PRIVINO = 0, ADEID_PRIVSYN = 210b1146, ADEID_PRIVID = 210b114e). Apr 28 13:55:08.081694 afpd[15783] {ad_open.c:826} (error:ad): ad_header_read_ea("/Pool/Global/Backup/Backup-Vagabond/Vagabond-M1.sparsebundle/mapped"): invalid metadata EA this is now being treated as a fatal error. if you see this log entry, please file a bug ticket with your upstream vendor and attach the generated core file (nentries = 8, ADEID_NUM_EA = 8 ADEID_FINDERI = 210b0fda, ADEID_FILEDATESI = 210b10c2, ADEID_AFPFILEI = 210b10d2, ADEID_PRIVDEV = 0, ADEID_PRIVINO = 0, ADEID_PRIVSYN = 210b10e6, ADEID_PRIVID = 210b10ee). Apr 28 13:55:08.081986 afpd[15783] {ad_open.c:826} (error:ad): ad_header_read_ea("/Pool/Global/Backup/Backup-Vagabond/Vagabond-M1.sparsebundle/mapped/."): invalid metadata EA this is now being treated as a fatal error. if you see this log entry, please file a bug ticket with your upstream vendor and attach the generated core file (nentries = 8, ADEID_NUM_EA = 8 ADEID_FINDERI = 210b103a, ADEID_FILEDATESI = 210b1122, ADEID_AFPFILEI = 210b1132, ADEID_PRIVDEV = 0, ADEID_PRIVINO = 0, ADEID_PRIVSYN = 210b1146, ADEID_PRIVID = 210b114e). Apr 28 13:55:08.087206 afpd[15783] {ad_open.c:826} (error:ad): ad_header_read_ea("/Pool/Global/Backup/Backup-Vagabond/Vagabond-M1.sparsebundle/Info.plist"): invalid metadata EA this is now being treated as a fatal error. if you see this log entry, please file a bug ticket with your upstream vendor and attach the generated core file (nentries = 8, ADEID_NUM_EA = 8 ADEID_FINDERI = 341e578a, ADEID_FILEDATESI = 341e5872, ADEID_AFPFILEI = 341e5882, ADEID_PRIVDEV = 0, ADEID_PRIVINO = 0, ADEID_PRIVSYN = 341e5896, ADEID_PRIVID = 341e589e). Apr 28 13:55:08.087252 afpd[15783] {ad_open.c:1288} (error:ad): ad_open_hf_ea: unexpected: Invalid argument Apr 28 13:55:08.087264 afpd[15783] {fork.c:423} (error:AFPDaemon): afp_openfork(Info.plist): ad_open: Invalid argument Apr 28 13:55:08.089753 afpd[15783] {ad_open.c:826} (error:ad): ad_header_read_ea("/Pool/Global/Backup/Backup-Vagabond/Vagabond-M1.sparsebundle/Info.plist"): invalid metadata EA this is now being treated as a fatal error. if you see this log entry, please file a bug ticket with your upstream vendor and attach the generated core file (nentries = 8, ADEID_NUM_EA = 8 ADEID_FINDERI = 210b103a, ADEID_FILEDATESI = 210b1122, ADEID_AFPFILEI = 210b1132, ADEID_PRIVDEV = 0, ADEID_PRIVINO = 0, ADEID_PRIVSYN = 210b1146, ADEID_PRIVID = 210b114e). Apr 28 13:55:08.090893 afpd[15783] {ad_open.c:826} (error:ad): ad_header_read_ea("/Pool/Global/Backup/Backup-Vagabond/Vagabond-M1.sparsebundle/bands"): invalid metadata EA this is now being treated as a fatal error. if you see this log entry, please file a bug ticket with your upstream vendor and attach the generated core file (nentries = 8, ADEID_NUM_EA = 8 ADEID_FINDERI = 210b0fda, ADEID_FILEDATESI = 210b10c2, ADEID_AFPFILEI = 210b10d2, ADEID_PRIVDEV = 0, ADEID_PRIVINO = 0, ADEID_PRIVSYN = 210b10e6, ADEID_PRIVID = 210b10ee). Apr 28 13:55:08.091262 afpd[15783] {ad_open.c:826} (error:ad): ad_header_read_ea("/Pool/Global/Backup/Backup-Vagabond/Vagabond-M1.sparsebundle/bands/."): invalid metadata EA this is now being treated as a fatal error. if you see this log entry, please file a bug ticket with your upstream vendor and attach the generated core file (nentries = 8, ADEID_NUM_EA = 8 ADEID_FINDERI = 210b103a, ADEID_FILEDATESI = 210b1122, ADEID_AFPFILEI = 210b1132, ADEID_PRIVDEV = 0, ADEID_PRIVINO = 0, ADEID_PRIVSYN = 210b1146, ADEID_PRIVID = 210b114e). Apr 28 13:55:08.096328 afpd[15783] {ad_open.c:826} (error:ad): ad_header_read_ea("/Pool/Global/Backup/Backup-Vagabond/Vagabond-M1.sparsebundle/bands/0"): invalid metadata EA this is now being treated as a fatal error. if you see this log entry, please file a bug ticket with your upstream vendor and attach the generated core file (nentries = 8, ADEID_NUM_EA = 8 ADEID_FINDERI = 210b103a, ADEID_FILEDATESI = 210b1122, ADEID_AFPFILEI = 210b1132, ADEID_PRIVDEV = 0, ADEID_PRIVINO = 0, ADEID_PRIVSYN = 210b1146, ADEID_PRIVID = 210b114e). Apr 28 13:55:08.146902 afpd[15783] {auth.c:804} (note:AFPDaemon): AFP logout by angelbox Apr 28 13:55:08.147949 afpd[15783] {afp_dsi.c:108} (note:AFPDaemon): AFP statistics: 8.29 KB read, 6.31 KB written Apr 28 13:55:08.148000 afpd[15783] {dircache.c:615} (info:AFPDaemon): dircache statistics: entries: 8, lookups: 74, hits: 63, misses: 11, added: 8, removed: 0, expunged: 0, evicted: 0 Apr 28 13:55:08.148068 afpd[15783] {afp_dsi.c:584} (note:AFPDaemon): done Apr 28 13:55:08.150085 afpd[33331] {main.c:151} (info:AFPDaemon): child[15783]: done Apr 28 14:05:08.257253 cnid_metad[33332] {cnid_metad.c:548} (info:CNID): cnid_dbd[97245] exited with exit code 1
FYI - affected systems has lots of 'dysfunctional' behaviours through AFP, such as: - Photoshop failing (sometimes, not always) to save modifications to an existing and open file (disk error) - TimeMachine not completing - error 22 volume not found So it's not just those EA messages in the log, it affects functionality. Here is a log extract that seem to indicate that the afpd process is crashing - not sure if that's what it really means Apr 28 15:46:17.436750 afpd[13093] {ad_open.c:1288} (error:ad): ad_open_hf_ea: unexpected: Invalid argument Apr 28 15:46:17.438031 cnid_metad[4848] {netatalk_conf.c:283} (warn:AFPDaemon): volume "Courant-Historiques" does not support Extended Attributes or read-only volume Apr 28 15:46:17.438248 cnid_metad[4848] {netatalk_conf.c:283} (warn:AFPDaemon): volume "Archives-Historiques" does not support Extended Attributes or read-only volume Apr 28 15:46:17.445144 afpd[13093] {ad_open.c:826} (error:ad): ad_header_read_ea("/Pool/Global/Backup/Backup-Vagabond"): invalid metadata EA this is now being treated as a fatal error. if you see this log entry, please file a bug ticket with your upstream vendor and attach the generated core file (nentries = 8, ADEID_NUM_EA = 8 ADEID_FINDERI = 20fa727a, ADEID_FILEDATESI = 20fa7362, ADEID_AFPFILEI = 20fa7372, ADEID_PRIVDEV = 0, ADEID_PRIVINO = 0, ADEID_PRIVSYN = 0, ADEID_PRIVID = 0). Apr 28 15:46:17.445214 afpd[13093] {ad_open.c:1288} (error:ad): ad_open_hf_ea: unexpected: Invalid argument Apr 28 15:46:17.454992 afpd[13093] {ad_open.c:826} (error:ad): ad_header_read_ea("/Pool/Global/Backup/Backup-Vagabond/."): invalid metadata EA this is now being treated as a fatal error. if you see this log entry, please file a bug ticket with your upstream vendor and attach the generated core file (nentries = 8, ADEID_NUM_EA = 8 ADEID_FINDERI = 20fa73fa, ADEID_FILEDATESI = 20fa74e2, ADEID_AFPFILEI = 20fa74f2, ADEID_PRIVDEV = 0, ADEID_PRIVINO = 0, ADEID_PRIVSYN = 0, ADEID_PRIVID = 0). Apr 28 15:46:17.456589 afpd[13093] {ad_open.c:826} (error:ad): ad_header_read_ea("/Pool/Global/Backup/Backup-Vagabond/."): invalid metadata EA this is now being treated as a fatal error. if you see this log entry, please file a bug ticket with your upstream vendor and attach the generated core file (nentries = 8, ADEID_NUM_EA = 8 ADEID_FINDERI = 20fa73fa, ADEID_FILEDATESI = 20fa74e2, ADEID_AFPFILEI = 20fa74f2, ADEID_PRIVDEV = 0, ADEID_PRIVINO = 0, ADEID_PRIVSYN = 0, ADEID_PRIVID = 0). Apr 28 15:46:17.500000 afpd[4847] {main.c:149} (info:AFPDaemon): child[13094]: exited 4 Apr 28 15:46:17.515992 afpd[4847] {main.c:149} (info:AFPDaemon): child[13095]: exited 4 Apr 28 15:46:17.526189 afpd[4847] {main.c:149} (info:AFPDaemon): child[13096]: exited 4 Apr 28 15:46:17.984556 afpd[13093] {ad_open.c:826} (error:ad): ad_header_read_ea("/Pool/Global/Backup/Backup-Vagabond/Vagabond-M1.sparsebundle"): invalid metadata EA this is now being treated as a fatal error. if you see this log entry, please file a bug ticket with your upstream vendor and attach the generated core file (nentries = 8, ADEID_NUM_EA = 8 ADEID_FINDERI = 20fa728a, ADEID_FILEDATESI = 20fa7372, ADEID_AFPFILEI = 20fa7382, ADEID_PRIVDEV = 0, ADEID_PRIVINO = 0, ADEID_PRIVSYN = 20fa7396, ADEID_PRIVID = 20fa739e).
Please post your _full_ afp.conf.
(In reply to Joe Marcus Clarke from comment #8) ; ; Netatalk 3.x configuration file ; [Global] log file = /var/log/netatalk.log log level = default:info uam list = uams_guest.so,uams_dhx2.so [Courant] path = /Pool/Global/Storage/Courant valid users = @users file perm = 0660 directory perm = 0770 read only = yes [Courant-Historiques] path = /Pool/Global/Storage/Courant/.zfs/snapshot/ valid users = @users [Archives-Historiques] path = /Pool/Global/Storage/Archives/.zfs/snapshot/ valid users = @users [Archives] path = /Pool/Global/Storage/Archives valid users = @users file perm = 0660 directory perm = 0770 read only = yes [Backup-MacBookPro] path = /Pool/Global/Backup/Backup-MacBookPro valid users = @users [Backup-Vagabond] path = /Pool/Global/Backup/Backup-Vagabond valid users = @users vol size limit = 1250000 time machine = yes
Also getting this in the log - I do not know if it is related. The pool doesn't have issues and it is very unlikely that it really failed to provide a requested file, it performs with good performance and without problems. Apr 28 19:31:02.250358 afpd[48686] {socket.c:164} (error:AFPDaemon): read: Operation timed out Apr 28 19:31:02.250432 afpd[48686] {dsi_stream.c:504} (error:DSI): dsi_stream_read: len:-1, Operation timed out Apr 28 19:31:02.250456 afpd[48686] {dsi_stream.c:504} (error:DSI): dsi_stream_read: len:0, unexpected EOF Apr 28 19:31:02.250472 afpd[48686] {dsi_stream.c:259} (note:DSI): dsi_disconnect: entering disconnected state
(In reply to c.tineo from comment #10) Actually it seem to be related: cat /var/log/netatalk.log | grep 48686 results in over 2000 lines with [48686] mixing entries such as this: Apr 28 18:53:50.186347 afpd[48686] {ad_open.c:826} (error:ad): ad_header_read_ea("/Pool/Global/Storage/Archives"): invalid metadata EA this is now being treated as a fatal error. if you see this log entry, please file a bug ticket with your upstream vendor and attach the generated core file (nentries = 8, ADEID_NUM_EA = 8 ADEID_FINDERI = 20620e2a, ADEID_FILEDATESI = 20620f12, ADEID_AFPFILEI = 20620f22, ADEID_PRIVDEV = 0, ADEID_PRIVINO = 0, ADEID_PRIVSYN = 0, ADEID_PRIVID = 0). Apr 28 18:53:50.193673 afpd[48686] {ad_open.c:826} (error:ad): ad_header_read_ea("/Pool/Global/Storage/Archives"): invalid metadata EA this is now being treated as a fatal error. if you see this log entry, please file a bug ticket with your upstream vendor and attach the generated core file (nentries = 8, ADEID_NUM_EA = 8 ADEID_FINDERI = 20620e2a, ADEID_FILEDATESI = 20620f12, ADEID_AFPFILEI = 20620f22, ADEID_PRIVDEV = 0, ADEID_PRIVINO = 0, ADEID_PRIVSYN = 0, ADEID_PRIVID = 0). and entries like this : Apr 28 18:39:02.122812 afpd[48686] {socket.c:164} (error:AFPDaemon): read: Operation timed out Apr 28 18:39:02.122887 afpd[48686] {dsi_stream.c:504} (error:DSI): dsi_stream_read: len:-1, Operation timed out Apr 28 18:39:02.122912 afpd[48686] {dsi_stream.c:504} (error:DSI): dsi_stream_read: len:0, unexpected EOF Apr 28 18:39:02.122933 afpd[48686] {dsi_stream.c:259} (note:DSI): dsi_disconnect: entering disconnected state Apr 28 18:53:50.178331 afpd[48682] {server_child.c:256} (note:Default): Reconnect: transferring session to child[48686] Apr 28 18:53:50.178530 afpd[48686] {afp_dsi.c:188} (note:AFPDaemon): afp_dsi_transfer_session: succesfull primary reconnect
Try shutting down netatalk and moving /var/netatalk to another location. Recreate the directory, and then restart netatalk. I suspect that the move from 32-bit dev/ino to 64-bit may be causing some issues.
(In reply to Joe Marcus Clarke from comment #12) Did what you asked. permissions for /var/netatalk are: drwxr-xr-x 2 root wheel 512 Apr 28 23:36 netatalk/ content of /var/netatalk is: root@abch022:/var/netatalk # ls -lah total 16 drwxr-xr-x 2 root wheel 512B Apr 28 23:36 . drwxr-xr-x 26 root wheel 512B Apr 28 23:35 .. -rw-r--r-- 1 root wheel 290B Apr 28 23:36 afp_signature.conf -rw-r--r-- 1 root wheel 333B Apr 29 09:43 afp_voluuid.conf Now getting this in the logs (below): Apr 29 09:42:16.979716 cnid_metad[92068] {netatalk_conf.c:283} (warn:AFPDaemon): volume "Courant-Historiques" does not support Extended Attributes or read-only volume ... previous message repeated >20 times (volumes named *-Historique are read-only volume - they point at <volume>/.zfs/snapshot - to give read-only access to zfs snapshots + has been defined in afp.conf with read only = yes Apr 28 23:37:32.217598 netatalk[92018] {netatalk.c:447} (note:Default): Netatalk AFP server starting Apr 28 23:37:32.225528 cnid_metad[92068] {cnid_metad.c:510} (note:AFPDaemon): CNID Server listening on localhost:4700 Apr 28 23:37:32.229185 afpd[92067] {status.c:644} (info:AFPDaemon): signature is 436D39619502237430BA411EDD0FAD4F Apr 28 23:37:32.230953 netatalk[92018] {afp_avahi.c:94} (info:AFPDaemon): hostname: abch022 Apr 28 23:37:32.230994 netatalk[92018] {afp_avahi.c:118} (info:AFPDaemon): Registering server 'abch022' with Bonjour Apr 28 23:37:32.232276 netatalk[92018] {afp_avahi.c:314} (info:AFPDaemon): Successfully started avahi loop. Apr 28 23:37:32.232332 netatalk[92018] {netatalk.c:517} (note:Default): Registered with Zeroconf Apr 28 23:37:32.405489 afpd[92067] {auth.c:111} (info:AFPDaemon): uam: "DHX2" available Apr 28 23:37:32.405537 afpd[92067] {auth.c:111} (info:AFPDaemon): uam: "No User Authent" available Apr 28 23:37:32.405551 afpd[92067] {status.c:363} (info:AFPDaemon): servername: abch022 Apr 28 23:37:32.405585 afpd[92067] {afp_config.c:198} (note:AFPDaemon): Netatalk AFP/TCP listening on 83.76.150.19:548 Apr 28 23:37:32.405630 afpd[92067] {cnid.c:55} (info:AFPDaemon): Registering CNID module [last] Apr 28 23:37:32.405641 afpd[92067] {cnid.c:55} (info:AFPDaemon): Registering CNID module [dbd] Apr 28 23:37:32.405650 afpd[92067] {cnid.c:55} (info:AFPDaemon): Registering CNID module [tdb] Apr 29 09:41:50.873993 afpd[37368] {dsi_tcp.c:241} (info:DSI): AFP/TCP session from 192.168.1.102:49578 Apr 29 09:41:50.874467 afpd[92067] {main.c:149} (info:AFPDaemon): child[37367]: exited 4 Apr 29 09:41:50.876920 afpd[92067] {main.c:151} (info:AFPDaemon): child[37368]: done Apr 29 09:41:50.909438 afpd[37369] {dsi_tcp.c:241} (info:DSI): AFP/TCP session from 192.168.1.102:49579 Apr 29 09:41:50.911000 afpd[37369] {uams_dhx2_passwd.c:265} (info:UAMS): DHX2 login: angelbox Apr 29 09:41:51.645871 afpd[37369] {auth.c:235} (note:AFPDaemon): Login by angelbox (AFP3.4) Apr 29 09:41:51.784199 afpd[37369] {ad_open.c:826} (error:ad): ad_header_read_ea("/Pool/Global/Storage/Archives"): invalid metadata EA this is now being treated as a fatal error. if you see this log entry, please file a bug ticket with your upstream vendor and attach the generated core file (nentries = 8, ADEID_NUM_EA = 8 ADEID_FINDERI = 205eacfa, ADEID_FILEDATESI = 205eade2, ADEID_AFPFILEI = 205eadf2, ADEID_PRIVDEV = 0, ADEID_PRIVINO = 0, ADEID_PRIVSYN = 0, ADEID_PRIVID = 0). Apr 29 09:41:51.786292 cnid_metad[92068] {cnid_metad.c:322} (error:CNID): set_dbdir: mkdir failed for /var/netatalk/CNID//ArchivesAFP/ ... previous message repeated >20 times Apr 29 09:42:12.964668 afpd[37369] {cnid_dbd.c:414} (error:CNID): transmit: Request to dbd daemon (volume ArchivesAFP) timed out. Apr 29 09:42:12.964701 afpd[37369] {volume.c:871} (error:AFPDaemon): afp_openvol(/Pool/Global/Storage/Archives): Fatal error: Unable to get stamp value from CNID backend Apr 29 09:42:12.965890 afpd[37369] {ad_open.c:1168} (error:Default): ad->ad_ops->ad_mkrf(ad_p) failed: Operation not supported Apr 29 09:42:12.967258 cnid_metad[92068] {cnid_metad.c:322} (error:CNID): set_dbdir: mkdir failed for /var/netatalk/CNID//ArchivesAFP/ ... previous message repeated >20 times Apr 29 09:42:33.697315 afpd[37369] {cnid_dbd.c:414} (error:CNID): transmit: Request to dbd daemon (volume Archives-Historiques) timed out. Apr 29 09:42:33.697371 afpd[37369] {volume.c:871} (error:AFPDaemon): afp_openvol(/Pool/Global/Storage/Archives/.zfs/snapshot): Fatal error: Unable to get stamp value from CNID backend Apr 29 09:42:33.699227 afpd[37369] {ad_open.c:1168} (error:Default): ad->ad_ops->ad_mkrf(ad_p) failed: Operation not supported Apr 29 09:42:33.701361 cnid_metad[92068] {cnid_metad.c:322} (error:CNID): set_dbdir: mkdir failed for /var/netatalk/CNID//Courant-Historiques/ ... previous message repeated >20 times Apr 29 09:42:54.675036 afpd[37369] {cnid_dbd.c:414} (error:CNID): transmit: Request to dbd daemon (volume Courant-Historiques) timed out. Apr 29 09:42:54.675066 afpd[37369] {volume.c:871} (error:AFPDaemon): afp_openvol(/Pool/Global/Storage/Courant/.zfs/snapshot): Fatal error: Unable to get stamp value from CNID backend Apr 29 09:42:54.699506 afpd[37369] {ad_open.c:826} (error:ad): ad_header_read_ea("/Pool/Global/Storage/Courant"): invalid metadata EA this is now being treated as a fatal error. if you see this log entry, please file a bug ticket with your upstream vendor and attach the generated core file (nentries = 8, ADEID_NUM_EA = 8 ADEID_FINDERI = 205eacfa, ADEID_FILEDATESI = 205eade2, ADEID_AFPFILEI = 205eadf2, ADEID_PRIVDEV = 0, ADEID_PRIVINO = 0, ADEID_PRIVSYN = 0, ADEID_PRIVID = 0). Apr 29 09:42:54.701051 cnid_metad[92068] {cnid_metad.c:322} (error:CNID): set_dbdir: mkdir failed for /var/netatalk/CNID//CourantAFP/ ... previous message repeated >20 times Apr 29 09:43:15.774548 afpd[37369] {cnid_dbd.c:414} (error:CNID): transmit: Request to dbd daemon (volume CourantAFP) timed out. Apr 29 09:43:15.774577 afpd[37369] {volume.c:871} (error:AFPDaemon): afp_openvol(/Pool/Global/Storage/Courant): Fatal error: Unable to get stamp value from CNID backend Apr 29 09:43:15.776620 afpd[37369] {auth.c:804} (note:AFPDaemon): AFP logout by angelbox Apr 29 09:43:15.777443 afpd[37369] {dsi_stream.c:504} (error:DSI): dsi_stream_read: len:0, unexpected EOF Apr 29 09:43:15.777464 afpd[37369] {afp_dsi.c:517} (note:AFPDaemon): afp_over_dsi: client logged out, terminating DSI session Apr 29 09:43:15.777568 afpd[37369] {afp_dsi.c:108} (note:AFPDaemon): AFP statistics: 0.73 KB read, 0.64 KB written Apr 29 09:43:15.777593 afpd[37369] {dircache.c:615} (info:AFPDaemon): dircache statistics: entries: 0, lookups: 0, hits: 0, misses: 0, added: 0, removed: 0, expunged: 0, evicted: 0 Apr 29 09:43:15.779683 afpd[92067] {main.c:151} (info:AFPDaemon): child[37369]: done also, many entries of (have been removed from above); Apr 29 09:42:16.979716 cnid_metad[92068] {netatalk_conf.c:283} (warn:AFPDaemon): volume "Courant-Historiques" does not support Extended Attributes or read-only volume
You could pull out the tests for DEV, INO, etc. (though I'm not sure why they're NULL/0 at this point). That would remove the "fatal" nature of this message and might restore enough of 3.1.12 behavior to get you working. I'd like to see the output of "stat /Pool/Global/Storage/Archives" just to see if there is some weirdness in layout of those file systems.
Do you have a firewall on this host? Any reason why you wouldn't be able to make a TCP connection to localhost:4700? Is the CNID server running?
(In reply to Joe Marcus Clarke from comment #14) stat: root@abch022:~ # stat /Pool/Global/Storage/Archives 10808480630835336939 4 drwxrws--- 37 root users 18446744073709551615 43 "Apr 28 14:53:35 2023" "Apr 28 14:53:35 2023" "May 2 02:23:54 2023" "Jul 2 13:12:30 2012" 16384 94 0x800 /Pool/Global/Storage/Archives root@abch022:~ # stat /Pool/Global/Storage/Courant 3758088818134678095 4 drwxrws--- 9 root users 18446744073709551615 13 "Apr 28 14:58:16 2023" "Apr 28 14:58:16 2023" "May 2 02:18:46 2023" "Jul 2 13:12:35 2012" 16384 71 0x800 /Pool/Global/Storage/Courant I do not know how to 'pull out the tests for DEV, INO, etc.' - do you mean remove some files from the source and recompile/build the package? No firewall on this host. Here are some relevant lines (partial extract) of sockstat -4 - so it seems that cnid is indeed running on port 4700 root@abch022:~ # sockstat -4 USER COMMAND PID FD PROTO LOCAL ADDRESS FOREIGN ADDRESS root cnid_metad 92068 4 tcp4 127.0.0.1:4700 *:* root afpd 92067 4 tcp46 *:548 *:* avahi avahi-daem 753 14 udp4 *:5353 *:* avahi avahi-daem 753 16 udp4 *:59621 *:*
Hmmm, I wouldn't expect afpd to timeout talking to cnid_metad, though. What about: ping -4 localhost And do you have any of the blackhole sysctls set?
(In reply to Joe Marcus Clarke from comment #17) Hello. If you need access to some of the systems that present the issues, let me know we can arrange that. No blackhole anything, pretty standard installation of freebsd. root@abch022:~ # ping -4 localhost PING localhost (127.0.0.1): 56 data bytes 64 bytes from 127.0.0.1: icmp_seq=0 ttl=64 time=0.060 ms 64 bytes from 127.0.0.1: icmp_seq=1 ttl=64 time=0.068 ms 64 bytes from 127.0.0.1: icmp_seq=2 ttl=64 time=0.073 ms 64 bytes from 127.0.0.1: icmp_seq=3 ttl=64 time=0.091 ms We are having several systems that exhibit the problem discussed on this ticket. Basically this means that Netatalk on freebsd + zfs is not working and that puts us in a real bind because we need FreeBSD + zfs + netatalk...
You did say that 3.1.12 worked for you? If you don't mind not having the extra security and data checking that went into 3.1.13+, you could revert the port to the older version. I have a feeling the ZFS bits are causing some of those AppleDouble fields to fail the validation, but I can't validate in my own setup.
(In reply to Joe Marcus Clarke from comment #19) Is there anything we can do to help you reproduce this issue. We're seeing it on every freebsd + zfs + netatalk 3.1.14 machine we have. What is the process for installing a prior version? Can we specify a version number when doing 'pkg install'?
I was thinking you can install the old version from ports. I've attached the old port. Clone the ports repo or have the ports subsystem installed, replace net/netatalk3 with the extracted directory from the netatalk3.tar.gz file, and then build with "make all deinstall install".
Created attachment 242496 [details] Old netatalk 3.1.12 port
(In reply to Joe Marcus Clarke from comment #22) Thank you for providing a process for manually installing an older version. But... Shouldn't the current version be fixed - because at this point it's "FreeBSD + ZFS => NO Netatalk" and that means no ability to upgrade through port upgrade. That's a big road block and I can't believe we're the only ones using Netatalk3 on zfs + freebsd ! For us it's a lot of work to revert all the netatalk 3.14 we have had automatically upgraded to a manually installed 3.12. Is this the end of Netatalk and we REALLY need to transition to Samba? If that's the case - we've been piecing together a sort of home-made smb4.conf but there's a lot that remains blurry because of the docs/tutos out there dont' necessarily apply to ZFS + FreeBSD + MacClients. - any good smb4.conf on ZFS + FreeBSD to point us towards? - and how to make Spotlight work on it? - and how to make windows versions (shadow copies) work with zfs snapshots through samba4? Do you have any docs or post with some known-good configuration to recommend? Thank you in advance for your help.
Netatalk 3.1.15 just came out. You _might_ try it out, but I am not optimistic it will fix ZFS support. Honestly, I don't have the resources to test and run down these ZFS bugs. I suggest you open an issue upstream at https://github.com/Netatalk/netatalk/issues as I think this requires some deeper changes in the software itself. I'm not going to close this bug out as I agree it seems like a real problem. I just think it needs more attention from the core netatalk team.
Hello. I confirm that reverting to 3.1.12 through compiling the source, resolves the issues reported her. I couldn't yet try 3.1.15 as it wasn't available in pkg yet, will add test results when I can. Did you open a bug report on Netatalk issues (as you may have more detail to give about what is happening / where - than we do) - or should we do it? Best, Cedric
Checkout 3.1.16. It looks ike they may have licked the remaining invalid metadata issues.
Installed 3.16 - on FreeBSD 13.2p3 - File Systems being shared are on ZFS no more 'metadata' errors in netatalk.log But many of these two: Sep 20 11:25:09.164354 afpd[85028] {fork.c:1070} (error:AFPDaemon): afp_closefork: of_find(256) could not locate fork Sep 20 14:07:26.053974 afpd[24546] {main.c:149} (info:AFPDaemon): child[47280]: exited 4 What does it mean? What impact does it have? What to do?
meant 3.1.16 (of course) . netatalk3-3.1.16,1
confirming - many of those "exited 4" errors per minute, even coming in bursts of 4, when there is activity over afp. From the client side the operations complete and the volume doesn't disconnect, so this error only 'shows' on the server side Sep 20 16:31:26.291210 afpd[24546] {main.c:149} (info:AFPDaemon): child[75483]: exited 4 Sep 20 16:31:26.324511 afpd[24546] {main.c:149} (info:AFPDaemon): child[75484]: exited 4 Sep 20 16:31:26.360715 afpd[24546] {main.c:149} (info:AFPDaemon): child[75485]: exited 4 Sep 20 16:31:26.394007 afpd[24546] {main.c:149} (info:AFPDaemon): child[75486]: exited 4 Sep 20 16:33:05.259553 afpd[24546] {main.c:149} (info:AFPDaemon): child[75494]: exited 4 Sep 20 16:33:05.290161 afpd[24546] {main.c:149} (info:AFPDaemon): child[75495]: exited 4 Sep 20 16:33:05.326890 afpd[24546] {main.c:149} (info:AFPDaemon): child[75496]: exited 4 Sep 20 16:33:05.359255 afpd[24546] {main.c:149} (info:AFPDaemon): child[75497]: exited 4
And also getting these... Sep 20 16:52:35.605569 afpd[85040] {dsi_stream.c:504} (error:DSI): dsi_stream_read: len:0, unexpected EOF Sep 20 16:52:35.605712 afpd[85040] {dsi_stream.c:259} (note:DSI): dsi_disconnect: entering disconnected state
I'd need a full backtrace with symbols to be sure, but I think this is normal OS X 10.3 behavior. The exit 4 is a closed connection. Are you seeing any other ill effects?
These additional messages seem to confirm this is client probes triggering disconnects.
Not seeing any ill effects, only those log entries in netatalk.log and I do not know if they should be ignored or are indicative of something/somewhere going wrong. Yes the client that was generating the activity was an OS X 13.4 - so if it is normal behaviour, fine by me.
Checked the logs for 3.1.12 - and it was never reporting those exited 4 messages. And does it make sense that client closing a connection will result in 4 identical lines in the log - everytime? So I wonder if this is really just 'normal' and to be ignored, and in this case it's new with 3.1.16 - or if it is the sign of something that is not working optimally? I would love to put this to rest and be confident that all is well - it's just that once we push this to hundred of client servers, if something's wrong, the consequences can be dire at that scale.
The saga continues. Netatalk 3.1.16 on a FreeBSD 12.4-p5 many many entries like this in /var/log/netatalk.log Sep 28 18:43:45.229941 afpd[55422] {ad_open.c:828} (error:ad): ad_header_read_ea("/Pool/Global/Storage/Archives/BUREAU 2016"): invalid metadata EA this is now being treated as a fatal error. if you see this log entry, please file a bug ticket with your upstream vendor and attach the generated core file. Sep 28 18:43:45.230035 afpd[55422] {ad_open.c:828} (error:ad): ad_header_read_ea("/Pool/Global/Storage/Archives/.TemporaryItems"): invalid metadata EA this is now being treated as a fatal error. if you see this log entry, please file a bug ticket with your upstream vendor and attach the generated core file. Sep 28 18:43:45.230131 afpd[55422] {ad_open.c:828} (error:ad): ad_header_read_ea("/Pool/Global/Storage/Archives/Comptabilité 2017-2018-2019_2020"): invalid metadata EA this is now being treated as a fatal error. if you see this log entry, please file a bug ticket with your upstream vendor and attach the generated core file.
Please open an issue at https://github.com/Netatalk/netatalk/issues.
I brought in a fix from upstream to fix some AppleDouble issues. Are you still seeing problems with 3.1.18_1?
Hi. Just upgraded a few machines to 3.18.1_1 and let them run for about a day. These types of errors DIDN'T show up in the logs in the <24h time that 3.18.1_1 ran: Jan 03 11:43:42.981242 afpd[9821] {ad_open.c:828} (error:ad): ad_header_read_ea("/Pool/Global/Storage/Archives/The Nagini Project/Swat Sculptures/Swat-Sculptures-2023/Export-Web/HAR-Bonhams-HK-Avalokiteshvara-Swat-01.jpg"): invalid metadata EA this is now being treated as a fatal error. if you see this log entry, please file a bug ticket with your upstream vendor and attach the generated core file. So it might be fixed! Probably unrelated but: I have some of those errors in the logs of one of the servers though: Jan 09 15:35:40.813572 afpd[80798] {fork.c:1070} (error:AFPDaemon): afp_closefork: of_find(256) could not locate fork Jan 09 15:35:40.873323 afpd[80798] {fork.c:1070} (error:AFPDaemon): afp_closefork: of_find(256) could not locate fork Jan 09 15:35:40.886736 afpd[80798] {fork.c:1070} (error:AFPDaemon): afp_closefork: of_find(256) could not locate fork Jan 09 15:35:40.901347 afpd[80798] {fork.c:1070} (error:AFPDaemon): afp_closefork: of_find(256) could not locate fork Jan 09 15:35:40.902828 afpd[80798] {fork.c:1070} (error:AFPDaemon): afp_closefork: of_find(256) could not locate fork Jan 09 15:36:35.795165 afpd[80798] {fork.c:1070} (error:AFPDaemon): afp_closefork: of_find(256) could not locate fork And also one of these on the first server: Jan 09 12:15:34.475337 afpd[80798] {socket.c:163} (error:AFPDaemon): read: Operation timed out Jan 09 12:15:34.475411 afpd[80798] {dsi_stream.c:504} (error:DSI): dsi_stream_read: len:-1, Operation timed out Jan 09 12:15:34.475452 afpd[80798] {dsi_stream.c:504} (error:DSI): dsi_stream_read: len:0, unexpected EOF Jan 09 12:15:34.475470 afpd[80798] {dsi_stream.c:259} (note:DSI): dsi_disconnect: entering disconnected state also here, second server: Jan 08 21:57:35.256082 afpd[33737] {socket.c:163} (error:AFPDaemon): read: Operation timed out Jan 08 21:57:35.256317 afpd[33737] {dsi_stream.c:504} (error:DSI): dsi_stream_read: len:-1, Operation timed out Jan 08 21:57:35.256407 afpd[33737] {afp_dsi.c:523} (note:AFPDaemon): afp_over_dsi: failed reconnect Jan 08 21:57:35.261957 afpd[33737] {afp_dsi.c:108} (note:AFPDaemon): AFP statistics: 11.34 KB read, 3.19 KB written Jan 08 21:57:35.262078 afpd[33737] {dircache.c:615} (info:AFPDaemon): dircache statistics: entries: 4, lookups: 225, hits: 221, misses: 4, added: 4, removed: 0, expunged: 0, evicted: 0 Jan 08 21:57:35.262151 afpd[33737] {dsi_stream.c:319} (error:DSI): dsi_stream_write: Broken pipe Are the above errors something to worry about?
The DSI errors, no. I suspect those are TCP/network related issues. The fork errors, probably not. A missing fork may have been a product of the previous issues, and it doesn't point to corruption issues.
The return of the "invalid metadata EA [...] treated as fatal error" log messages. FreeBSD 14.0p6 Netatalk3-3.1.18-3,1 May 09 12:40:04.689857 afpd[1058] {ad_open.c:829} (error:ad): ad_header_read_ea("/Pool/Tineo/Global/Storage/Courant/aaaaa dispatch aaaaaa"): invalid metadata EA this is now being treated as a fatal error. if you see this log entry, please file a bug ticket with your upstream vendor and attach the generated core file. May 09 12:40:04.689959 afpd[1058] {ad_open.c:829} (error:ad): ad_header_read_ea("/Pool/Tineo/Global/Storage/Courant/.DS_Store"): invalid metadata EA this is now being treated as a fatal error. if you see this log entry, please file a bug ticket with your upstream vendor and attach the generated core file. + various logged items that I do not know how to interpret, are they issues or to be ignored ? - many afpd exited 4 messages. What is 4 as an exit code? May 09 12:40:02.875668 afpd[928] {main.c:149} (info:AFPDaemon): child[1085]: exited 4 - Invalid argument - as in: May 09 12:40:32.398897 afpd[1058] {ad_open.c:1287} (error:ad): ad_open_hf_ea: unexpected: Invalid argument May 09 12:40:32.398913 afpd[1058] {fork.c:423} (error:AFPDaemon): afp_openfork(.DS_Store): ad_open: Invalid argument May 09 12:40:32.403668 afpd[1058] {ad_open.c:829} (error:ad): ad_header_read_ea("/Pool/Tineo/Global/Storage/Courant/.DS_Store"): invalid metadata EA this is now being treated as a fatal error. if you see this log entry, please file a bug ticket with your upstream vendor and attach the generated core file. May 09 12:40:32.403689 afpd[1058] {ad_open.c:1287} (error:ad): ad_open_hf_ea: unexpected: Invalid argument May 09 12:40:32.403703 afpd[1058] {fork.c:423} (error:AFPDaemon): afp_openfork(.DS_Store): ad_open: Invalid argument May 09 12:40:02.755839 afpd[928] {main.c:149} (info:AFPDaemon): child[1082]: exited 4 May 09 12:40:02.788364 afpd[928] {main.c:149} (info:AFPDaemon): child[1083]: exited 4 May 09 12:40:02.837750 afpd[928] {main.c:149} (info:AFPDaemon): child[1084]: exited 4 May 09 12:40:02.875668 afpd[928] {main.c:149} (info:AFPDaemon): child[1085]: exited 4 May 09 12:40:03.432034 afpd[928] {main.c:149} (info:AFPDaemon): child[1086]: exited 4 May 09 12:40:03.466599 afpd[928] {main.c:149} (info:AFPDaemon): child[1087]: exited 4 May 09 12:40:03.505300 afpd[928] {main.c:149} (info:AFPDaemon): child[1088]: exited 4 May 09 12:40:03.566131 afpd[928] {main.c:149} (info:AFPDaemon): child[1089]: exited 4 May 09 12:40:03.605888 afpd[928] {main.c:149} (info:AFPDaemon): child[1090]: exited 4 May 09 12:40:03.644370 afpd[928] {main.c:149} (info:AFPDaemon): child[1091]: exited 4 May 09 12:40:04.680285 afpd[1058] {ad_open.c:829} (error:ad): ad_header_read_ea("/Pool/Tineo/Global/Storage/Archives/CT_photo_movies_archive"): invalid metadata EA this is now being treated as a fatal error. if you see this log entry, please file a bug ticket with your upstream vendor and attach the generated core file. May 09 12:40:04.680480 afpd[1058] {ad_open.c:829} (error:ad): ad_header_read_ea("/Pool/Tineo/Global/Storage/Archives/.DS_Store"): invalid metadata EA this is now being treated as a fatal error. if you see this log entry, please file a bug ticket with your upstream vendor and attach the generated core file. May 09 12:40:04.689593 afpd[1058] {ad_open.c:829} (error:ad): ad_header_read_ea("/Pool/Tineo/Global/Storage/Courant/newSoftware Archives"): invalid metadata EA this is now being treated as a fatal error. if you see this log entry, please file a bug ticket with your upstream vendor and attach the generated core file. May 09 12:40:04.689665 afpd[1058] {ad_open.c:829} (error:ad): ad_header_read_ea("/Pool/Tineo/Global/Storage/Courant/newSoftware to Sort"): invalid metadata EA this is now being treated as a fatal error. if you see this log entry, please file a bug ticket with your upstream vendor and attach the generated core file. May 09 12:40:04.689857 afpd[1058] {ad_open.c:829} (error:ad): ad_header_read_ea("/Pool/Tineo/Global/Storage/Courant/aaaaa dispatch aaaaaa"): invalid metadata EA this is now being treated as a fatal error. if you see this log entry, please file a bug ticket with your upstream vendor and attach the generated core file. May 09 12:40:04.689959 afpd[1058] {ad_open.c:829} (error:ad): ad_header_read_ea("/Pool/Tineo/Global/Storage/Courant/.DS_Store"): invalid metadata EA this is now being treated as a fatal error. if you see this log entry, please file a bug ticket with your upstream vendor and attach the generated core file. May 09 12:40:25.492473 afpd[1058] {ad_open.c:829} (error:ad): ad_header_read_ea("/Pool/Tineo/Global/Storage/Courant/newSoftware Archives"): invalid metadata EA this is now being treated as a fatal error. if you see this log entry, please file a bug ticket with your upstream vendor and attach the generated core file. May 09 12:40:25.492585 afpd[1058] {ad_open.c:829} (error:ad): ad_header_read_ea("/Pool/Tineo/Global/Storage/Courant/newSoftware to Sort"): invalid metadata EA this is now being treated as a fatal error. if you see this log entry, please file a bug ticket with your upstream vendor and attach the generated core file. May 09 12:40:25.492781 afpd[1058] {ad_open.c:829} (error:ad): ad_header_read_ea("/Pool/Tineo/Global/Storage/Courant/aaaaa dispatch aaaaaa"): invalid metadata EA this is now being treated as a fatal error. if you see this log entry, please file a bug ticket with your upstream vendor and attach the generated core file. May 09 12:40:25.492879 afpd[1058] {ad_open.c:829} (error:ad): ad_header_read_ea("/Pool/Tineo/Global/Storage/Courant/.DS_Store"): invalid metadata EA this is now being treated as a fatal error. if you see this log entry, please file a bug ticket with your upstream vendor and attach the generated core file. May 09 12:40:25.622301 afpd[1058] {ad_open.c:829} (error:ad): ad_header_read_ea("/Pool/Tineo/Global/Storage/Archives/CT_photo_movies_archive"): invalid metadata EA this is now being treated as a fatal error. if you see this log entry, please file a bug ticket with your upstream vendor and attach the generated core file. May 09 12:40:25.622479 afpd[1058] {ad_open.c:829} (error:ad): ad_header_read_ea("/Pool/Tineo/Global/Storage/Archives/.DS_Store"): invalid metadata EA this is now being treated as a fatal error. if you see this log entry, please file a bug ticket with your upstream vendor and attach the generated core file. May 09 12:40:32.395311 afpd[1058] {ad_open.c:829} (error:ad): ad_header_read_ea("/Pool/Tineo/Global/Storage/Courant/.DS_Store"): invalid metadata EA this is now being treated as a fatal error. if you see this log entry, please file a bug ticket with your upstream vendor and attach the generated core file. May 09 12:40:32.398865 afpd[1058] {ad_open.c:829} (error:ad): ad_header_read_ea("/Pool/Tineo/Global/Storage/Courant/.DS_Store"): invalid metadata EA this is now being treated as a fatal error. if you see this log entry, please file a bug ticket with your upstream vendor and attach the generated core file. May 09 12:40:32.398897 afpd[1058] {ad_open.c:1287} (error:ad): ad_open_hf_ea: unexpected: Invalid argument May 09 12:40:32.398913 afpd[1058] {fork.c:423} (error:AFPDaemon): afp_openfork(.DS_Store): ad_open: Invalid argument May 09 12:40:32.403668 afpd[1058] {ad_open.c:829} (error:ad): ad_header_read_ea("/Pool/Tineo/Global/Storage/Courant/.DS_Store"): invalid metadata EA this is now being treated as a fatal error. if you see this log entry, please file a bug ticket with your upstream vendor and attach the generated core file. May 09 12:40:32.403689 afpd[1058] {ad_open.c:1287} (error:ad): ad_open_hf_ea: unexpected: Invalid argument May 09 12:40:32.403703 afpd[1058] {fork.c:423} (error:AFPDaemon): afp_openfork(.DS_Store): ad_open: Invalid argument May 09 12:40:38.284177 afpd[1058] {ad_open.c:829} (error:ad): ad_header_read_ea("/Pool/Tineo/Global/Storage/Courant/.DS_Store"): invalid metadata EA this is now being treated as a fatal error. if you see this log entry, please file a bug ticket with your upstream vendor and attach the generated core file. May 09 12:40:38.288081 afpd[1058] {ad_open.c:829} (error:ad): ad_header_read_ea("/Pool/Tineo/Global/Storage/Courant/.DS_Store"): invalid metadata EA this is now being treated as a fatal error. if you see this log entry, please file a bug ticket with your upstream vendor and attach the generated core file. May 09 12:40:38.288108 afpd[1058] {ad_open.c:1287} (error:ad): ad_open_hf_ea: unexpected: Invalid argument May 09 12:40:38.288124 afpd[1058] {fork.c:423} (error:AFPDaemon): afp_openfork(.DS_Store): ad_open: Invalid argument May 09 12:40:38.292298 afpd[1058] {ad_open.c:829} (error:ad): ad_header_read_ea("/Pool/Tineo/Global/Storage/Courant/.DS_Store"): invalid metadata EA this is now being treated as a fatal error. if you see this log entry, please file a bug ticket with your upstream vendor and attach the generated core file. May 09 12:40:38.292319 afpd[1058] {ad_open.c:1287} (error:ad): ad_open_hf_ea: unexpected: Invalid argument May 09 12:40:38.292334 afpd[1058] {fork.c:423} (error:AFPDaemon): afp_openfork(.DS_Store): ad_open: Invalid argument