puzzling AFP permissions problem

[sjk]

[I originally sent this to the macosx-admin list but haven’t received any replies. Although the problem occurs on OS X Client systems I thought someone here with more in-depth AFP expertise might be able to help. I’ll also add this happens over ethernet and wlan connections. I’m baffled.]

Calling AFP gurus …

A couple days ago I discovered a permissions problem that’s mysteriously afflicting every AFP-mounted volume on all three of my home systems (running 10.4.6 client). I’ve spent most of the afternoon trying to figure this out and am about out of ideas to avoid more drastic measures (e.g. combo update, archive & install, full reinstall) attempting to fix it without knowing the cause. Might be the result of something I installed or ran on each system around the same time but I haven’t found any correlation. And I’m not sure when it started, overlooked with Finder-only activity, though at least for a week.

First symptom I noticed was peculiar "ls -l" output for a remote mounted boot volume that contained duplicate entries(!) for usr and Volumes directories and the var symlink. Also, the owner:group permissions were the login uid:gid (admin account) instead of the normal systemish ones, as though "Ignore ownership on this volume" were enabled. When running the "ls -l" as root the group changed to unknown (gid 99).

A bit later I noticed unusual messages in system.log on the client, like:

Apr 27 17:13:45 host kernel[0]: AFP_VFS afpfs_mount: /Volumes/Macintosh HD-1, pid 4999
Apr 27 17:13:45 host kernel[0]: AFP_VFS afpfs_getnewvnode: illegal node id of 0 for Network
Apr 27 17:15:32 host kernel[0]: AFP_VFS afpfs_vhashremove: illegal node id of 0 for Network
Apr 27 17:15:32 host kernel[0]: AFP_VFS afpfs_unmount: /Volumes/Macintosh HD-1, flags 0, pid 5016
Apr 27 17:15:32 host kernel[0]: AFP_VFS afpfs_unmount: afpfs_flushfiles failed 16

On the server end all permissions look normal. With AppleFileServer logging enabled there were some duplicate entries in AppleFileServiceAccess.log like:

!!Log File Created On: 4/28/2006 17:47:56 117:5:0 GMT
**** – – [28/Apr/2006:17:47:57 -1000] "Mounted Volume Tiger" 0 0 0
**** – – [28/Apr/2006:17:47:57 -1000] "DiskArbStart -" 0 6403 0
IP 1.2.3.4 – – [28/Apr/2006:17:49:56 -1000] "Login User Name" 0 0 0
IP 1.2.3.4 – – [28/Apr/2006:17:49:57 -1000] "OpenFork .DS_Store" 0 0 0
IP 1.2.3.4 – – [28/Apr/2006:17:50:14 -1000] "OpenFork etc" 0 0 0
IP 1.2.3.4 – – [28/Apr/2006:17:50:14 -1000] "OpenFork etc" 0 0 0
IP 1.2.3.4 – – [28/Apr/2006:17:50:14 -1000] "OpenFork mach" 0 0 0
IP 1.2.3.4 – – [28/Apr/2006:17:50:14 -1000] "OpenFork mach" 0 0 0
IP 1.2.3.4 – – [28/Apr/2006:17:50:14 -1000] "OpenFork tmp" 0 0 0
IP 1.2.3.4 – – [28/Apr/2006:17:50:14 -1000] "OpenFork tmp" 0 0 0
IP 1.2.3.4 – – [28/Apr/2006:17:50:14 -1000] "OpenFork var" 0 0 0
IP 1.2.3.4 – – [28/Apr/2006:17:50:14 -1000] "OpenFork var" 0 0 0
IP 1.2.3.4 – – [28/Apr/2006:17:50:14 -1000] "OpenFork var" 0 0 0
IP 1.2.3.4 – – [28/Apr/2006:17:50:14 -1000] "OpenFork var" 0 0 0
IP 1.2.3.4 – – [28/Apr/2006:17:51:17 -1000] "Logout User Name" 0 0 0

… when running "ls -l" on the client.

I’ve done the Disk Utility and DiskWarrior rituals. I’ve stopped/restarted AppleFileServer and rebooted plenty of times. I’ve noticed a check_afp process running as root but haven’t figured out how that might be involved. Deleting com.apple.AppleFileServer.plist and letting it be recreated was in vain. Researching this on the web was fruitless. One thing left to do is boot from a mostly generic system volume and see if that reveals anything new. I’m still not even sure if this a server or client problem.

Any clues to help solve this mystery would be appreciated. I have a hunch it may be trivial to fix, just that I don’t know the magic incantation for undoing whatever did it. Thanks!

-sjk

[pete]

I have the same problem it’s happening for me on my Xserve Raid Partitioned Boot and Shared volumes. I am going to break it apart and recreate it. I think may be happening as the result of upgrading and existing OLDER RAID setup from a previous MAC OS X Server version.

[sjk]

Thanks for responding, Pete. It’s a relief finally knowing someone else has seen this problem though obviously I’d rather it weren’t happening to anyone at all. Still no solution or new insights after a bit more tinkering.

Btw, I also had a problem with the "invisible" attribute bit of the separate /Users volume (mounted with a UUID entry in /etc/fstab) being enabled, which DiskWarrior repaired and caused some weird Finder-related symptoms to disappear. And it happened "randomly" one other time, but not again since toggling it visible again and setting Finder prefs to display hard disks on the Desktop to hopefully notice it sooner. I think there’s some correlation between that and the AFP permission snafu.

Interesting you think your problem may be a side effect of a RAID volume upgrade. I’ve had similar speculation about having used iPartition to resize volumes on two of my three systems (and iDefrag Lite on all three). I’ll be contacting Coriolis Systems about that possibility sometime this week.

Back again later when there’s anything worthwhile to report …

[Author]

Posts