Really hoping someone can help. This has been happening consistently for the last couple of months, starting with OSX 10.7.3 and 4.1.8. I'm now on 4.1.9 [T15], same issue.
I tried renaming the /etc/netatalk folder, re-installing the Raidiator software [T15]. It did re-create the folder with default settings, and I can start AFP, but as soon as I connect using OSX 10.7.4, the connection disappears, so the problem is still there. Any ideas? What can I do, short of starting from scratch?
Here's the process entry list showing AFP is running:
root 4035 0.0 0.5 2400 1184 ? Ss 10:11 0:00 /frontview/bin/monitor_enclosure
root 4180 0.0 0.3 2016 896 ttyS1 Ss+ 10:11 0:00 /sbin/getty -L ttyS1 9600 vt100
root 5518 0.6 7.1 21712 16112 ? Ss 10:12 0:12 /usr/sbin/apache-ssl -f /etc/frontview/apache/httpd.conf
admin 5684 3.1 8.8 25456 20000 ? S 10:13 0:56 /usr/sbin/apache-ssl -f /etc/frontview/apache/httpd.conf
admin 5719 2.9 8.6 25216 19552 ? S 10:13 0:53 /usr/sbin/apache-ssl -f /etc/frontview/apache/httpd.conf
root 5753 0.1 2.0 13840 4560 ? Ss 10:13 0:02 sshd: root@pts/0
root 5756 0.0 1.0 5712 2464 pts/0 Ss 10:13 0:00 -bash
root 5849 0.0 0.4 2912 1072 ? S 10:14 0:00 /usr/sbin/cnid_metad -l log_info -f /var/log/netatalk.log
root 7140 0.0 0.4 2624 1088 ? S 10:41 0:00 /usr/sbin/atalkd
root 7180 39.2 1.3 6640 2960 ? S 10:41 0:32 /usr/sbin/afpd -U uams_dhx.so,uams_dhx2.so,uams_clrtxt.so,uams_guest.so -c 50 -n READYNAS
Here's the (free -m) memory state before I try to connect, looks like there's still memory free:
total used free shared buffers cached
Mem: 221 215 5 0 15 164
-/+ buffers/cache: 35 185
Swap: 749 0 749
Here's the memory state after the connection drops:
total used free shared buffers cached
Mem: 221 188 32 0 15 100
-/+ buffers/cache: 72 148
Swap: 749 0 749
AFP log doesn't seem to show anything out of the ordinary:
Jun 16 10:41:53.819241 afpd[7180] {logger.c:406} (D5:Logger): Setup file logging: type: Default, level: LOG_MAXDEBUG, file: /var/log/netatalk.log
Jun 16 10:41:53.888820 afpd[7180] {status.c:740} (I:AFPDaemon): "READYNAS"'s signature is <REMOVED>
Jun 16 10:41:53.889381 afpd[7180] {afp_config.c:347} (D5:AFPDaemon): DSIConfigInit: hostname: READYNAS, ip/port: default/548,
Jun 16 10:41:53.908459 afpd[7180] {dsi_tcp.c:316} (I:DSI): dsi_tcp_init: socket: Address family not supported by protocol
Jun 16 10:41:53.913890 afpd[7180] {afp_config.c:364} (N:AFPDaemon): AFP/TCP started, advertising <REMOVED>:548 (2-2-2-p3)
Jun 16 10:41:53.914271 afpd[7180] {auth.c:1146} (D5:AFPDaemon): uam: loading (/usr/lib/netatalk/uams_dhx.so)
Jun 16 10:41:53.995934 afpd[7180] {auth.c:1153} (D5:AFPDaemon): uam: uams_dhx.so loaded
Jun 16 10:41:53.996195 afpd[7180] {auth.c:1146} (D5:AFPDaemon): uam: loading (/usr/lib/netatalk/uams_dhx2.so)
Jun 16 10:41:53.999321 afpd[7180] {uams_dhx2_pam.c:925} (D5:UAMS): DHX2: generating mersenne primes
Jun 16 10:42:32.057337 afpd[7180] {auth.c:1153} (D5:AFPDaemon): uam: uams_dhx2.so loaded
Jun 16 10:42:32.057618 afpd[7180] {auth.c:1146} (D5:AFPDaemon): uam: loading (/usr/lib/netatalk/uams_guest.so)
Jun 16 10:42:32.059541 afpd[7180] {auth.c:1153} (D5:AFPDaemon): uam: uams_guest.so loaded
Jun 16 10:42:32.060143 afpd[7180] {auth.c:136} (I:AFPDaemon): uam: "No User Authent" available
Jun 16 10:42:32.060403 afpd[7180] {auth.c:136} (I:AFPDaemon): uam: "DHX2" available
Jun 16 10:42:32.060583 afpd[7180] {auth.c:136} (I:AFPDaemon): uam: "DHCAST128" available
Jun 16 10:42:32.060864 afpd[7180] {afp_config.c:580} (D5:AFPDaemon): Finished parsing Config File
Jun 16 10:42:32.061225 afpd[7180] {volume.c:1968} (D5:AFPDaemon): load_volumes: AFP MASTER
Jun 16 10:42:32.066636 afpd[7180] {volume.c:1247} (D10:AFPDaemon): readvolfile: seeding default umask: 0000
Jun 16 10:42:32.066876 afpd[7180] {volume.c:1259} (D5:AFPDaemon): readvolfile: "/etc/netatalk/AppleVolumes.system"
Jun 16 10:42:32.096475 afpd[7180] {volume.c:619} (D5:AFPDaemon): createvol: Volume 'homes'
Jun 16 10:42:32.097117 afpd[7180] {volume.c:661} (D10:AFPDaemon): createvol: Volume 'homes' -> UTF8-MAC Name: 'homes'
Jun 16 10:42:32.097397 afpd[7180] {volume.c:699} (D10:AFPDaemon): createvol: Volume 'homes' -> Longname: 'homes'
Jun 16 10:42:32.098239 afpd[7180] {acls.c:1786} (D5:AFPDaemon): Volume "/c/home" ACL support: yes
Jun 16 10:42:32.099862 afpd[7180] {vfs.c:1168} (D5:AFPDaemon): initvol_vfs: enabling EA support with native EAs
Jun 16 10:42:32.100443 afpd[7180] {volume.c:1247} (D10:AFPDaemon): readvolfile: seeding default umask: 0000
Jun 16 10:42:32.100664 afpd[7180] {volume.c:1259} (D5:AFPDaemon): readvolfile: "/etc/netatalk/AppleVolumes.default"
Jun 16 10:42:32.102026 afpd[7180] {volume.c:619} (D5:AFPDaemon): createvol: Volume 'backup'
Jun 16 10:42:32.102347 afpd[7180] {volume.c:661} (D10:AFPDaemon): createvol: Volume 'backup' -> UTF8-MAC Name: 'backup'
Jun 16 10:42:32.102567 afpd[7180] {volume.c:699} (D10:AFPDaemon): createvol: Volume 'backup' -> Longname: 'backup'
Jun 16 10:42:32.102968 afpd[7180] {acls.c:1786} (D5:AFPDaemon): Volume "/backup" ACL support: yes
Jun 16 10:42:32.104191 afpd[7180] {vfs.c:1168} (D5:AFPDaemon): initvol_vfs: enabling EA support with native EAs
Jun 16 10:42:32.104632 afpd[7180] {cnid.c:53} (I:AFPDaemon): Registering CNID module [dbd]
Jun 16 10:42:32.104832 afpd[7180] {cnid.c:53} (I:AFPDaemon): Registering CNID module [tdb]
Jun 16 10:42:32.105032 afpd[7180] {socket.c:445} (D5:Default): fdset_add_fd: adding fd 5 in slot 0
Jun 16 10:42:32.105253 afpd[7180] {socket.c:464} (D5:Default): fdset_add_fd: initialized with space for 87 conncections
Jun 16 10:42:32.105573 afpd[7180] {main.c:423} (D10:AFPDaemon): main: polling 1 fds
System Log doesn't show anything obvious either:
Jun 16 10:41:20 READYNAS avahi-daemon[1136]: Service "READYNAS (AFP)" (/etc/avahi/services/afp.service) successfully established.
Jun 16 10:41:20 READYNAS atalkd[7115]: zip_getnetinfo for eth0
Jun 16 10:41:21 READYNAS atalkd[7115]: done
Jun 16 10:41:21 READYNAS atalkd[7140]: Set syslog logging to level: LOG_INFO
Jun 16 10:41:21 READYNAS atalkd[7140]: restart (2-2-2-p3)
Jun 16 10:41:22 READYNAS atalkd[7140]: zip_getnetinfo for eth0
Jun 16 10:41:42 READYNAS last message repeated 2 times
Jun 16 10:41:52 READYNAS atalkd[7140]: config for no router
Jun 16 10:41:53 READYNAS atalkd[7140]: ready 0/0/0
Jun 16 10:47:02 READYNAS noflushd[1039]: Spinning down disks.
Jun 16 10:47:26 READYNAS noflushd[1039]: Disks spinning up after 0 minutes.
