AFP Share Issues

[thegert87]

AFP Broken after 8.0.1 B4?

I believe that there is a new AFP bug from the jump from 8.0.1 Beta 4 to 8.0.1 RC1 and RC2. After a fresh install of 8.0.1 RC1 AFP would act awkwardly with Time Machine. Time Machine would try to perform an hourly backup and after a arbitrary amount of time the back up would seem to have completed, but either "failed" in the background or I would actually receive an error from TM that it failed. If the backup "failed" in the background the next hourly backup would be the same size as the previous. This morning I fresh installed 8.0.1 RC2 but AFP seems to still be broken.... Here is some CLI output with viewing AFP settings...

Following output is after boot:
Sep 24 13:51:58 wildebeast proftpd[1623]: 127.0.0.1 - ProFTPD 1.3.3e (maint) (built Fri Sep 16 2011 20:42:35 UTC) standalone mode STARTUP
Sep 24 13:51:59 wildebeast avahi-daemon[1679]: WARNING: No NSS support for mDNS detected, consider installing nss-mdns!
Sep 24 13:51:59 wildebeast cnid_metad[1689]: Set syslog logging to level: LOG_NOTE
Sep 24 13:51:59 wildebeast [1691]: Set syslog logging to level: LOG_NOTE
Sep 24 13:51:59 wildebeast afpd[1692]: AFP/TCP started, advertising 98.111.***.***:548 (2.2.0)
Sep 24 13:52:02 wildebeast freenas[1705]: Popen()ing: zpool list -H -o health zebra
Sep 24 13:52:04 wildebeast INADYN[1775]: I:INADYN: IP address for alias 'wildebeast.***.com' needs update to '98.111.***.***'
Sep 24 13:52:04 wildebeast INADYN[1775]: I:INADYN: Alias 'wildebeast.***.com' to IP '98.111.***.***' updated successful.
Sep 24 13:52:13 wildebeast ntpd[1459]: time reset +1.537455 s
Sep 24 13:55:02 wildebeast freenas[2317]: Popen()ing: zpool list -H -o health zebra

Why is AFP advertising on my external ip address?!

This next output is the response of disabling AFP via GUI

Sep 24 14:03:30 wildebeast freenas[1703]: Executing: /usr/sbin/service ix-afpd quietstart
Sep 24 14:03:30 wildebeast freenas[1703]: Executing: /usr/sbin/service netatalk forcestop
Sep 24 14:03:30 wildebeast afpd[1692]: AFP Server shutting down on SIGTERM
Sep 24 14:03:30 wildebeast freenas[1703]: Executing: /usr/sbin/service dbus forcestop
Sep 24 14:03:30 wildebeast freenas: Stopping dbus.
Sep 24 14:03:30 wildebeast avahi-daemon[1679]: Disconnected from D-Bus, exiting.
Sep 24 14:03:30 wildebeast freenas[1703]: Executing: /usr/sbin/service dbus restart
Sep 24 14:03:31 wildebeast freenas: dbus not running? (check /var/run/dbus/dbus.pid).
Sep 24 14:03:31 wildebeast freenas: Starting dbus.
Sep 24 14:03:31 wildebeast freenas[1703]: Executing: /usr/sbin/service avahi-daemon forcestop
Sep 24 14:03:31 wildebeast freenas: Stopping avahi-daemon.
Sep 24 14:03:31 wildebeast freenas: Failed to kill daemon: No such file or directory
Sep 24 14:03:31 wildebeast freenas[1703]: Executing: /usr/sbin/service avahi-daemon restart
Sep 24 14:03:31 wildebeast freenas: Stopping avahi-daemon.
Sep 24 14:03:31 wildebeast freenas: Failed to kill daemon: No such file or directory
Sep 24 14:03:31 wildebeast freenas: Starting avahi-daemon.
Sep 24 14:03:31 wildebeast avahi-daemon[2868]: WARNING: No NSS support for mDNS detected, consider installing nss-mdns!
Sep 24 14:03:31 wildebeast freenas[1703]: Executing: /usr/sbin/service netatalk restart
Sep 24 14:03:31 wildebeast freenas: Will not 'restart' netatalk because netatalk_enable is NO.
Sep 24 14:03:31 wildebeast freenas[1703]: Executing: /bin/pgrep -F /var/run/afpd.pid afpd

Seems ok...
Next output is by restarting AFP from the GUI

Sep 24 14:07:52 wildebeast freenas[1703]: Executing: /usr/sbin/service netatalk restart
Sep 24 14:07:52 wildebeast freenas: No matching processes were found
Sep 24 14:07:52 wildebeast freenas: No matching processes were found
Sep 24 14:07:52 wildebeast cnid_metad[3288]: Set syslog logging to level: LOG_NOTE
Sep 24 14:07:52 wildebeast [3290]: Set syslog logging to level: LOG_NOTE
Sep 24 14:07:52 wildebeast afpd[3291]: AFP/TCP started, advertising 98.111.***.***:548 (2.2.0)
Sep 24 14:07:52 wildebeast freenas[1703]: Executing: /bin/pgrep -F /var/run/afpd.pid afpd
Sep 24 14:07:53 wildebeast afpd[3291]: bind(fd, (struct sockaddr *)&address, address_length) failed: Address already in use
Sep 24 14:07:53 wildebeast ntpd[1459]: kernel time sync status change 2001

AFP enabled...I guess, but still using my external ip...

This is the result of either just viewing the AFP Shares Settings and selecting OK, or changing a setting:

Sep 24 14:09:35 wildebeast freenas[1703]: Executing: /usr/sbin/service ix-afpd quietstart
Sep 24 14:09:35 wildebeast freenas[1703]: Executing: /usr/sbin/service ix-afpd quietstart
Sep 24 14:09:35 wildebeast freenas[1703]: Executing: /usr/sbin/service netatalk forcestop
Sep 24 14:09:35 wildebeast afpd[3291]: AFP Server shutting down on SIGTERM
Sep 24 14:09:35 wildebeast freenas[1703]: Executing: /usr/sbin/service dbus forcestop
Sep 24 14:09:36 wildebeast freenas: Stopping dbus.
Sep 24 14:09:36 wildebeast avahi-daemon[3273]: Disconnected from D-Bus, exiting.
Sep 24 14:09:36 wildebeast afpd[3291]: Failed to contact server: Daemon not running
Sep 24 14:09:36 wildebeast freenas[1703]: Executing: /usr/sbin/service dbus restart
Sep 24 14:09:36 wildebeast freenas: dbus not running? (check /var/run/dbus/dbus.pid).
Sep 24 14:09:36 wildebeast freenas: Starting dbus.
Sep 24 14:09:36 wildebeast freenas[1703]: Executing: /usr/sbin/service avahi-daemon forcestop
Sep 24 14:09:36 wildebeast freenas: Stopping avahi-daemon.
Sep 24 14:09:36 wildebeast freenas: Failed to kill daemon: No such file or directory
Sep 24 14:09:36 wildebeast freenas[1703]: Executing: /usr/sbin/service avahi-daemon restart
Sep 24 14:09:36 wildebeast freenas: Stopping avahi-daemon.
Sep 24 14:09:36 wildebeast freenas: Failed to kill daemon: No such file or directory
Sep 24 14:09:36 wildebeast freenas: Starting avahi-daemon.
Sep 24 14:09:36 wildebeast avahi-daemon[3522]: WARNING: No NSS support for mDNS detected, consider installing nss-mdns!
Sep 24 14:09:36 wildebeast freenas[1703]: Executing: /usr/sbin/service netatalk restart
Sep 24 14:09:36 wildebeast freenas: No matching processes were found
Sep 24 14:09:36 wildebeast cnid_metad[3537]: Set syslog logging to level: LOG_NOTE
Sep 24 14:09:36 wildebeast [3539]: Set syslog logging to level: LOG_NOTE
Sep 24 14:09:36 wildebeast afpd[3540]: dsi_tcp_init: no suitable network config for TCP socket
Sep 24 14:09:36 wildebeast afpd[3540]: main: dsi_init: Address already in use
Sep 24 14:09:36 wildebeast freenas[1703]: Executing: /bin/pgrep -F /var/run/afpd.pid afpd
Sep 24 14:09:37 wildebeast freenas[1703]: Executing: /bin/pgrep -F /var/run/afpd.pid afpd
Sep 24 14:09:37 wildebeast afpd[3540]: ===============================================================
Sep 24 14:09:37 wildebeast afpd[3540]: INTERNAL ERROR: Signal 11 in pid 3540 (2.2.0)
Sep 24 14:09:37 wildebeast afpd[3540]: ===============================================================
Sep 24 14:09:38 wildebeast kernel: pid 3540 (afpd), uid 0: exited on signal 6

WOOPS! AFP returns Signal 11 & 6... But the GUI reports no errors...


Just to confirm the status of afpd this is what TOP reports:
last pid: 6228; load averages: 0.00, 0.04, 0.06 up 0+00:25:32
14:17:04 45 processes: 2 running, 43 sleeping
Mem: 95M Active, 31M Inact, 141M Wired, 4372K Cache, 138M Buf, 3627M Free Swap: 6144M Total, 6144M Free
PID USERNAME THR PRI NICE SIZE RES STATE TIME WCPU COMMAND
1703 root 6 44 0 113M 60600K uwait 0:05 0.00% python
3291 root 1 44 0 20452K 3476K uwrlck 0:01 0.00% afpd

afp reports uwrlck?

So I reboot since AFP "is locked..." After rebooting, I will try to connect using AFP by afp://192.168.5.2/Time-Machine which I should receive a prompt to enter a user name and password... but instead I get an error from Finder "Connection Failed, You do not have the permissions to access the server "192.168.5.2" But for this share the permissions are 770, and the owner is the correct account. No settings have changed because it has just worked... Anyway, back to the finder error...
The only option is to click OK, but then this happens over and over again, there is no option to specify a user name and password, and I can't click cancel to stop trying to connect because there isn't a cancel button.
For each time I click ok, the FreeNAS server reports that "Sep 24 15:10:22 wildebeast afpd[4680]: AFP3.3 Login by sharing" which is the correct user name.

Next, I try to log onto to the Time-Machine Share through setting up a TM disk.
I see the appropriate share and it is listed as a TM device. I am offered to enter a user name and password, I do so, and then I receive this...
"The operation could not be completed (OSStatus error 13)"

So for now since AFP seems to be broken after 8.0.1 B4, I have disabled AFP...

If you have any insight please share...
I'm using 10.6.8 btw...
Thanks in advance.

 

[nogs_]

Hi All, just to add another voice to the issue I also am getting "Something wrong with the volume's CNID DB, using temporary CNID DB instead.Check server messages for details. Switching to read-only mode.". I'll let you know if I find anything useful.

 

[OneStickShortOfaBundle]

Hi All, just to add another voice to the issue I also am getting "Something wrong with the volume's CNID DB, using temporary CNID DB instead.Check server messages for details. Switching to read-only mode.". I'll let you know if I find anything useful.

Thanks. My Mac is far happier with afp than SAMBA so the sooner this is fixed the better.

 

[seggerman]

Hi All, just to add another voice to the issue I also am getting "Something wrong with the volume's CNID DB, using temporary CNID DB instead.Check server messages for details. Switching to read-only mode.". I'll let you know if I find anything useful.

I had this as well. I only log in via guest and the guest account didn't have write access to the filesystem. So either change the Guest account ID or change the permissions on the drive.

Worked for me.

Cheers

Alexander

 

[OneStickShortOfaBundle]

I had this as well. I only log in via guest and the guest account didn't have write access to the filesystem. So either change the Guest account ID or change the permissions on the drive.
Worked for me.
Cheers
Alexander

Thanks for the suggestion Alexander but I usually log on as a registered user so I should have read/write access. I have also tried logging in as a guest and changing permissions but it didn't make any difference. :(

Off topic - Why does FreeNAS sometimes change its address when restarted? I have to connect a monitor & keyboard each time this happens to find out what address to use. It's a nuisance.

 

[nogs_]

A quick update - I now cannot connect to freenas using AFP without getting the error mentioned and the share going to read-only mode. I have tried rebooting and recreating the share.

 

[OneStickShortOfaBundle]

Right now I am updating FreeNAS to RC2. I shall let you know if that makes any difference.

Update - Something has gone wrong. Since updating to RC2 I can no longer connect to my server at all. Eek! :(

 

[elafargue]

Since updating to the latest FreeNAS I get "Something wrong with the volume's CNID DB, using temporary CNID DB instead. Check server messages for details! Switching to Read- only mode."

As a result I can read from but not write to my server. I am waiting for someone to post a fix for this.

I had exactly the same problem after updating. The fix was simple in my case: I realized that the volume path was not writeable by the user I used to log on through AFP. In my case, my AFP share is at /mnt/storage/documents, which means that I had to make "documents" owned by the "users" group, and of course group-writeable. Worked for me...

 

[OneStickShortOfaBundle]

I had exactly the same problem after updating. The fix was simple in my case: I realized that the volume path was not writeable by the user I used to log on through AFP. In my case, my AFP share is at /mnt/storage/documents, which means that I had to make "documents" owned by the "users" group, and of course group-writeable. Worked for me...

Thanks elafargue. I shall give it a go. Unfortunately my router expired with a loud pop in the early hours this morning so I shall have to wait until the replacement arrives.

Update - OK I'm back up and running again but I cannot see a "users" group in the permissions options. My permissions are currently set to "wheel" which is what FreeNAS set them to by default. What should they be set to?
Update - I've just updated to FreeNAS-8.0.1-RELEASE-amd64 and still no joy. :(

Update - I have just set up a completely new NAS and installed FreeNAS-8.0.1-RELEASE-amd64 on it and exactly the same problem has reoccurred with the new AFP I made. How do I fix this?

I've also discovered this :- In addition to the CNID DB problem 43,033 invisible ‘.AppleDouble’ folders and 12,790 visible ‘I7CIPB~N’ files have appeared on my server. Is it safe for me to delete all these files?

Unfortunately http://support.freenas.org/ticket/763 has been closed but it has not resolved my problem. They propose that I should - ‘Adjust your permissions so your guest or login account can write the .AppleDB files to the share. Once you do that, the problems both you and I have seen above will go away.’

I would be very grateful to anyone who could explain to me how to do this.

 

[nogs_]

I decided to add an additional AFP share just to see what happened. Since then I have been able to access all my existing AFP shares without issue. No other changes made. It almost seems like some config changes made after adding the shares has corrupted them. Adding another share seems to have resolve the issue.

 

[OneStickShortOfaBundle]

I've just tried making a new share nogs but it made no difference. I still get the same error message. :(
Update - I've just updated to FreeNAS-8.0.1-RELEASE-amd64 and still no joy. :(

Update - I have just set up a completely new NAS and installed FreeNAS-8.0.1-RELEASE-amd64 on it and exactly the same problem has reoccurred with the new AFP I made. How do I fix this?

 

[pierrep]

I'm having the same issues with AFP in 8.0.1.RC2 and also in 8.0.1-RELEASE
Looks like we need to open a bug... I could not find any bug relating to this

 

[OneStickShortOfaBundle]

I'm having the same issues with AFP in 8.0.1.RC2 and also in 8.0.1-RELEASE
Looks like we need to open a bug... I could not find any bug relating to this

A ticket has already been opened here - http://support.freenas.org/ticket/763

 

[pierrep]

oh thanks !
i thought so but could not find it so i created a duplicate (which i closed...)

 

[OneStickShortOfaBundle]

I've also discovered this :- In addition to the CNID DB problem 43,033 invisible ‘.AppleDouble’ folders and 12,790 visible ‘I7CIPB~N’ files have appeared on my server. Is it safe for me to delete all these files?

 

[pierrep]

.AppleDouble are pretty normal
They're here to store data that is usually stored in the HFS+ filesystem by design but cannot be stored in other filesystems.These folders allow not to lose the extra info.

don't know anything about the files if they're not related to .AppleDoucle directory

I'm suspecting our current issue is linked to the fact the the cnid_dbd process is not running.
But i have not tried to re-run an 8.0-RELEASE to check that it's running in that version....

 

[OneStickShortOfaBundle]

.AppleDouble are pretty normal
They're here to store data that is usually stored in the HFS+ filesystem by design but cannot be stored in other filesystems.These folders allow not to lose the extra info.

don't know anything about the files if they're not related to .AppleDoucle directory

I'm suspecting our current issue is linked to the fact the the cnid_dbd process is not running.
But i have not tried to re-run an 8.0-RELEASE to check that it's running in that version....

Thanks for the info pierrep. I am running 8.0-RELEASE but I continue to get the error message.

 

[pierrep]

8.0-RELEASE and stil unable to run AFP correctly ?
quite weird as it was working perfectly well for me (although i was in i386 version not amd64)

 

[OneStickShortOfaBundle]

8.0-RELEASE and stil unable to run AFP correctly ?
quite weird as it was working perfectly well for me (although i was in i386 version not amd64)

I had hoped that someone could have told me how ro rebuild the volume's CNID DB. There must be some way to do this.

Here's something odd - the NAS I set up a few days ago has started working properly again with afp. Both NAS are identical right down to the brand of HD being used and Flash drives on which FreeNAS is installed.

Unfortunately http://support.freenas.org/ticket/763 has been closed but it has not resolved my problem. They propose that I should - ‘Adjust your permissions so your guest or login account can write the .AppleDB files to the share. Once you do that, the problems both you and I have seen above will go away.’

I would be very grateful to anyone who could explain to me how to do this.

 

[thegert87]

OneStickShortOfaBundle -- If you created a dedicated user for the TM share and didn't specify a group when doing so, the group name for that user should be the same as the user's name. Ie, I create a user account Alex, and don't specify the group, the default group of Alex will be created. So, in this case the new user would be Alex and he would be in the group Alex. If you can provide info on how you have created your TM share and how users authenticate to it would be appreciated... Best of luck in the mean time...

I figured out my own problem.... I created a dedicated user account for my TM share. I originally had permissions of the ZFS dataset with that user set for read/write, and ALSO had a password for the AFP share itself. Apparently TM didn't like the AFP share having a password. As soon as I removed that share password, I was still prompted to enter the user credentials to access the ZFS dataset and boom, it worked. Perhaps there was a change made somewhere along the line.... I used to be able to do both, meaning, the user account for the ZFS share, and a separate share password for the AFP TM share.....