NETGEAR is aware of a growing number of phone and online scams. To learn how to stay safe click here.
Forum Discussion
Readynas beta for Lion (AFP fix) hoses Mac
Hi,
First, thanks for your quick work addressing the Readynas Lion problems. For some reason, it's not working for me.
I've got an NV+. I installed the Readynas beta for Lion to get afp working again.
The afpd on the NAS is segfaulting in a loop. Something is working just well enough in the process that the mount attempt never gives up on my mac. Since the mount is underway, the finder is mostly useless and I can't cancel the mount. I can't do much of anything. It took a couple of tries until I restarted the NAS and completely disabled AFP on the it before I was able to do much of anything after I logged in on the Mac (my login items mount an AFP volume... it hoses things up enough that I couldn't bring up the settings utility to turn off the login item).
Hilarity.
Looking at the sourceforge code for netatalk, I don't see direct snprintf, but I'm guessing this may be some sort of a logging failure? That seems to be the main place that formatting is done?
Anyway, any help would be greatly appreciated.
[this repeats forever...]
Jul 21 19:25:02.889424 afpd[2811] {uams_dhx2_pam.c:321} (I:UAMS): DHX2 login: XXXX
Jul 21 19:25:04.094334 afpd[2811] {uams_dhx2_pam.c:210} (I:UAMS): PAM DHX2: PAM Success
Jul 21 19:25:04.109204 afpd[2811] {uams_dhx2_pam.c:653} (I:UAMS): DHX2: PAM Auth OK!
Jul 21 19:25:04.109544 afpd[2811] {auth.c:269} (N:AFPDaemon): AFP3.3 Login by XXXX
Jul 21 19:25:04.111969 afpd[2811] {auth.c:677} (N:AFPDaemon): afp_disconnect: trying primary reconnect
Jul 21 19:25:09.116178 afpd[2811] {auth.c:710} (E:AFPDaemon): afp_disconnect: primary reconnect failed
Jul 21 19:25:09.158863 afpd[2811] {volume.c:2129} (W:AFPDaemon): volume "USB_HDD_14" does not support Extended Attributes, using ea:ad instead
Jul 21 19:25:09.159925 afpd[2811] {volume.c:2036} (I:AFPDaemon): CNID server: localhost:4700
Jul 21 19:25:09.164454 afpd[2811] {fault.c:122} (S:Default): ===============================================================
Jul 21 19:25:09.164755 afpd[2811] {fault.c:123} (S:Default): INTERNAL ERROR: Signal 11 in pid 2811 (2-2-0-p5)
Jul 21 19:25:09.164975 afpd[2811] {fault.c:124} (S:Default): ===============================================================
Jul 21 19:25:09.165797 afpd[2811] {fault.c:96} (S:Default): BACKTRACE: 2 stack frames:
Jul 21 19:25:09.166098 afpd[2811] {fault.c:102} (S:Default): #0 /lib/libc.so.6(snprintf+0x1c) [0x201d0cd4]
Jul 21 19:25:09.166338 afpd[2811] {fault.c:102} (S:Default): #1 /usr/sbin/afpd(afp_options_parseline+0x166) [0x1c5d2]
Jul 21 19:25:09.168162 afpd[2168] {main.c:188} (I:AFPDaemon): child[2811]: killed by signal 6
Jul 21 19:25:09.271488 afpd[2835] {dsi_tcp.c:212} (I:DSI): AFP/TCP session from 192.168.123.112:49461
Jul 21 19:25:09.276759 afpd[2168] {server_ipc.c:231} (E:AFPDaemon): Reading IPC header failed (-1 of 14 bytes read): Resource temporarily unavailable
First, thanks for your quick work addressing the Readynas Lion problems. For some reason, it's not working for me.
I've got an NV+. I installed the Readynas beta for Lion to get afp working again.
The afpd on the NAS is segfaulting in a loop. Something is working just well enough in the process that the mount attempt never gives up on my mac. Since the mount is underway, the finder is mostly useless and I can't cancel the mount. I can't do much of anything. It took a couple of tries until I restarted the NAS and completely disabled AFP on the it before I was able to do much of anything after I logged in on the Mac (my login items mount an AFP volume... it hoses things up enough that I couldn't bring up the settings utility to turn off the login item).
Hilarity.
Looking at the sourceforge code for netatalk, I don't see direct snprintf, but I'm guessing this may be some sort of a logging failure? That seems to be the main place that formatting is done?
Anyway, any help would be greatly appreciated.
[this repeats forever...]
Jul 21 19:25:02.889424 afpd[2811] {uams_dhx2_pam.c:321} (I:UAMS): DHX2 login: XXXX
Jul 21 19:25:04.094334 afpd[2811] {uams_dhx2_pam.c:210} (I:UAMS): PAM DHX2: PAM Success
Jul 21 19:25:04.109204 afpd[2811] {uams_dhx2_pam.c:653} (I:UAMS): DHX2: PAM Auth OK!
Jul 21 19:25:04.109544 afpd[2811] {auth.c:269} (N:AFPDaemon): AFP3.3 Login by XXXX
Jul 21 19:25:04.111969 afpd[2811] {auth.c:677} (N:AFPDaemon): afp_disconnect: trying primary reconnect
Jul 21 19:25:09.116178 afpd[2811] {auth.c:710} (E:AFPDaemon): afp_disconnect: primary reconnect failed
Jul 21 19:25:09.158863 afpd[2811] {volume.c:2129} (W:AFPDaemon): volume "USB_HDD_14" does not support Extended Attributes, using ea:ad instead
Jul 21 19:25:09.159925 afpd[2811] {volume.c:2036} (I:AFPDaemon): CNID server: localhost:4700
Jul 21 19:25:09.164454 afpd[2811] {fault.c:122} (S:Default): ===============================================================
Jul 21 19:25:09.164755 afpd[2811] {fault.c:123} (S:Default): INTERNAL ERROR: Signal 11 in pid 2811 (2-2-0-p5)
Jul 21 19:25:09.164975 afpd[2811] {fault.c:124} (S:Default): ===============================================================
Jul 21 19:25:09.165797 afpd[2811] {fault.c:96} (S:Default): BACKTRACE: 2 stack frames:
Jul 21 19:25:09.166098 afpd[2811] {fault.c:102} (S:Default): #0 /lib/libc.so.6(snprintf+0x1c) [0x201d0cd4]
Jul 21 19:25:09.166338 afpd[2811] {fault.c:102} (S:Default): #1 /usr/sbin/afpd(afp_options_parseline+0x166) [0x1c5d2]
Jul 21 19:25:09.168162 afpd[2168] {main.c:188} (I:AFPDaemon): child[2811]: killed by signal 6
Jul 21 19:25:09.271488 afpd[2835] {dsi_tcp.c:212} (I:DSI): AFP/TCP session from 192.168.123.112:49461
Jul 21 19:25:09.276759 afpd[2168] {server_ipc.c:231} (E:AFPDaemon): Reading IPC header failed (-1 of 14 bytes read): Resource temporarily unavailable
21 Replies
Replies have been turned off for this discussion
- What version of Raidiator were you using before the upgrade?
Can you send in your logs so I can take a look at them. - Sorry, but I don't know the version. It was the latest. I had checked to see if I could get a standard upgrade that might fix the Lion thing before I tried the beta and it told me I was up to date.
Sending logs -- absolutely, you bet. Where do I send logs and what form do you like them in? - Directions to send logs are in my signature.
- Hm. So, I had an 8M log and was rejected because it was too large.
If you want to tell me some subset of logs I can zip them up for you explicitly?
Thanks again... - Try unzipping the logs, removing the backup job logs then zip them up again and try sending it to him again.
- I'm having the same problem - posted in viewtopic.php?f=17&t=55161&start=15
I found that I can connect fine as guest or another user. I only get the core dump when connecting as myself. This means time machine works fine since it uses the ReadyNAS ID. I get the difference from my account versus another even connecting to the same, brand new, empty share.
I thought it might have to do with auth info coming from the keychain, so I removed the saved password. No change. - I took packet captures when doing a successful mount using an alternate account and when failing using my own account, and compared.
There were only two differences up to the point where netatalk segfaulted, and they were both extra requests from the client on the failed side.
The Lion client did a 'FPMapID' request after getting user info, to map my numeric UID to my username. That returned a result so I don't think it's directly related to the problem.
Later, the lion client did an 'FPAccess' request on the share name. Shortly later, the connection is reset. I see this pattern recurring. Sometimes the client makes a second request before getting the RST (without waiting for a reply from fpaccess,) but that second request matches the behavior of the working username. The working username never makes a FPAccess request at all. FPAccess never returns a result at all.
It looks to me like there's a bug in netatalk's implementation of the FPAccess command. I see on the forum that other people who aren't seeing crashes are having problems with incorrect permissions on a share, only when using their own user ID. Since FPAccess is used to determine whether the user has access to a file, I bet that bug is directly related to this one. It's just a matter of what bad data the FPAccess function reads - garbage it can deal with, or garbage that causes a segfault. - By any chance is you UID/GID on your Mac the same as on the ReadyNAS? I was having an issue like this and I changed my accounts UID/GID on the NAS and it is working OK. I change it back and it starts to fail again.
- ...and in fact, I think I see the bug. It's in the UUID lookup function.
If the UUID is not found in the cache, and is not a local UID or GID, and you do not have LDAP, then everything falls through and an uninitialized NULL name is added to the cache as the ID corresponding to the UUID, and then it tries to log it. It seems to me like that fall through should return an error.
in libatalk/acl/uuid.c
217 int getnamefromuuid(const uuidp_t uuidp, char **name, uuidtype_t *type) {
218 int ret = 0;
219 uid_t uid;
220 gid_t gid;
221 struct passwd *pwd;
222 struct group *grp;
223
224 if (search_cachebyuuid(uuidp, name, type) == 0) {
225 /* found in cache */
226 LOG(log_debug, logtype_afpd,
227 "getnamefromuuid{cache}: UUID: %s -> name: %s, type%s: %s",
228 uuid_bin2string(uuidp),
229 *name,
230 (*type & UUID_ENOENT) == UUID_ENOENT ? "[negative]" : "",
231 uuidtype[(*type) & UUIDTYPESTR_MASK]);
232 if ((*type & UUID_ENOENT) == UUID_ENOENT)
233 return -1;
234 return 0;
235 }
236
237 /* not found in cache */
238
239 /* Check if UUID is a client local one */
240 if (memcmp(uuidp, local_user_uuid, 12) == 0) {
241 *type = UUID_USER;
242 uid = ntohl(*(uint32_t *)(uuidp + 12));
243 if ((pwd = getpwuid(uid)) == NULL) {
244 /* not found, add negative entry to cache */
245 add_cachebyuuid(uuidp, "UUID_ENOENT", UUID_ENOENT, 0);
246 ret = -1;
247 } else {
248 *name = strdup(pwd->pw_name);
249 add_cachebyuuid(uuidp, *name, *type, 0);
250 ret = 0;
251 }
252 LOG(log_debug, logtype_afpd,
253 "getnamefromuuid{local}: UUID: %s -> name: %s, type:%s",
254 uuid_bin2string(uuidp), *name, uuidtype[(*type) & UUIDTYPESTR_MASK]);
255 return ret;
256 } else if (memcmp(uuidp, local_group_uuid, 12) == 0) {
257 *type = UUID_GROUP;
258 gid = ntohl(*(uint32_t *)(uuidp + 12));
259 if ((grp = getgrgid(gid)) == NULL) {
260 /* not found, add negative entry to cache */
261 add_cachebyuuid(uuidp, "UUID_ENOENT", UUID_ENOENT, 0);
262 ret = -1;
263 } else {
264 *name = strdup(grp->gr_name);
265 add_cachebyuuid(uuidp, *name, *type, 0);
266 ret = 0;
267 }
268 return ret;
269 }
270
271 #ifdef HAVE_LDAP
272 ret = ldap_getnamefromuuid(uuid_bin2string(uuidp), name, type);
273 if (ret != 0) {
274 LOG(log_warning, logtype_afpd, "getnamefromuuid(%s): no result from ldap_getnamefromuuid",
275 uuid_bin2string(uuidp));
276 add_cachebyuuid(uuidp, "UUID_ENOENT", UUID_ENOENT, 0);
277 return -1;
278 }
279 #endif
280
281 add_cachebyuuid(uuidp, *name, *type, 0);
282
283 LOG(log_debug, logtype_afpd, "getnamefromuuid{LDAP}: UUID: %s -> name: %s, type:%s",
284 uuid_bin2string(uuidp), *name, uuidtype[(*type) & UUIDTYPESTR_MASK]);
285
286 return 0;
287 } - As a matter of fact, my ID number is the same on my mac and the readynas.
NETGEAR Academy
Boost your skills with the Netgear Academy - Get trained, certified and stay ahead with the latest Netgear technology!
Join Us!
