4

We've got a problem with OSX 10.6 clients seeing 'ghost' mount points to an OSX Server 10.5 over AFP. On occasion (5 times in the past month) the client machine seems to have some sort of connection problem with the server, and remounts the share. Finder looks OK during this entire process, but in /Volumes/ the old mount remains as a directory, and a new point point shows up in /Volumes/ with an incrementing suffix; E.g.:

lrwxr-xr-x   1 root    admin    1 Feb  3 12:39 Macintosh HD -> /
dr-x------@  9 cutter  staff  264 Jun  4  2008 Produktion
drwxrwxr-x  10 cutter  staff  408 Jan  5 07:44 Simplex TimeMachine
dr-x------@  7 cutter  staff  264 Jun  4  2008 Transfer
drwxr-xr-x+  3 cutter  admin  102 Jan 13 14:24 Voyager
drwxr-xr-x+  3 cutter  admin  102 Jan 18 10:28 Voyager-1
drwxr-xr-x+  3 cutter  admin  102 Jan 25 09:20 Voyager-2
drwxr-xr-x+  3 cutter  admin  102 Jan 25 16:31 Voyager-3
drwxr-xr-x+  3 cutter  admin  102 Feb  3 08:30 Voyager-4
drwx------@ 10 cutter  staff  296 Jan 13 13:12 Voyager-5

But Finder shows the users a normal 'Voyager' share, and there is no indication that any gremlins are at work.

OSX Finder Bug http://www.dietpizza.ch/images/finder-bug.png

While Finder allows people to navigate to what the target file on the share (we 'see' /Voyager/myfile.txt), any file path used in our software has the numbered suffix (like /Voyager-5/myfile.txt). Once the mount point is remounted with a new suffix (/Voyager-6), the old path becomes invalid. Our software keeps a permanent reference to the file, and when it tries to acces it, boom! But for the user looking at Finder, there is no apparent issue.

I've grep'd the system logs for clues, but don't really seem to have much to go on:

manoa:Logs stu$ grep mount *
system.log.4:Feb  3 08:53:33 Streaming1-MacPro fseventsd[38]: check_vol_last_mod_time:XXX failed to get mount time (25; &mount_time == 0x10043f8b8)
system.log.4:Feb  3 09:31:44 Streaming1-MacPro UnmountAssistant[811]: Volume unmounted successfully
system.log.5:Feb  2 09:28:56 Streaming1-MacPro UnmountAssistant[10763]: Volume unmounted successfully
system.log.6:Feb  1 12:26:17 Streaming1-MacPro UnmountAssistant[2277]: 
system.log.7:Jan 28 13:54:05 Streaming1-MacPro fseventsd[38]: check_vol_last_mod_time:XXX failed to get mount time (25; &mount_time == 0x10077f8b8)
system.log.7:Jan 28 13:55:34 Streaming1-MacPro UnmountAssistant[27673]: Volume unmounted successfully
system.log.7:Jan 28 13:55:36 Streaming1-MacPro UnmountAssistant[27673]: Volume unmounted successfully

and grep'ing for the time stamp of the last 'ghosting' of the share:

system.log.4:Feb  3 08:30:33 localhost com.apple.launchd[1]: *** launchd[1] has started up. ***
system.log.4:Feb  3 08:30:37 localhost mDNSResponder[17]: mDNSResponder mDNSResponder-214 (Oct 16 2009 06:09:30) starting
system.log.4:Feb  3 08:30:38 Streaming1-MacPro configd[15]: setting hostname to "Streaming1-MacPro.local"
system.log.4:Feb  3 08:30:38 Streaming1-MacPro configd[15]: network configuration changed.
system.log.4:Feb  3 08:30:42 Streaming1-MacPro bootlog[44]: BOOT_TIME: 1265182233 0
system.log.4:Feb  3 08:30:45 Streaming1-MacPro configd[15]: network configuration changed.
system.log.4:Feb  3 08:30:46 Streaming1-MacPro com.apple.usbmuxd[26]: usbmuxd-176 built for iTunesNineDot on Sep 24 2009 at 16:11:05, running 32 bit
system.log.4:Feb  3 08:30:46 Streaming1-MacPro configd[15]: network configuration changed.
system.log.4:Feb  3 08:30:46 Streaming1-MacPro com.intego.commonservices.daemon[53]: Using preferences format 3
system.log.4:Feb  3 08:30:46 Streaming1-MacPro com.apple.SystemStarter[27]: Starting Qmaster services
system.log.4:Feb  3 08:30:47 Streaming1-MacPro blued[45]: Apple Bluetooth daemon started
system.log.4:Feb  3 08:30:47 Streaming1-MacPro /System/Library/CoreServices/loginwindow.app/Contents/MacOS/loginwindow[34]: Login Window Application Started
system.log.4:Feb  3 08:30:49 Streaming1-MacPro loginwindow[34]: Login Window Started Security Agent
system.log.4:Feb  3 08:30:49 Streaming1-MacPro WindowServer[72]: kCGErrorFailure: Set a breakpoint @ CGErrorBreakpoint() to catch errors as they are logged.
system.log.4:Feb  3 08:30:49 Streaming1-MacPro com.apple.WindowServer[72]: Wed Feb  3 08:30:49 Streaming1-MacPro.local WindowServer[72] <Error>: kCGErrorFailure: Set a breakpoint @ CGErrorBreakpoint() to catch errors as they are logged.

There is networking stuff int there, but nothing scary.

There is a smattering of information on The Intertubes regarding similar problems, and most people seem to be saying:

  • Unmount the share
  • Delete old folders/shares remaining in /Volumes/
  • Restart
  • Add share back

These machines generally run 24/7 in a newsroom setting, and telling my production users 'just do these four technical tasks, and it will be ok for a few more days/weeks, and you will have to do again at some point' doesn't go over very well.

I would like a permanent fix--those pesky ghost volumes should go away and never come back!

Info on the client:

The output of mount:

/dev/disk0s2 on / (hfs, local, journaled)
devfs on /dev (devfs, local, nobrowse)
map -hosts on /net (autofs, nosuid, automounted, nobrowse)
map auto_home on /home (autofs, automounted, nobrowse)
/dev/disk1s2 on /Volumes/Simplex TimeMachine (hfs, local, nodev, nosuid, journaled)
afp_4gqctq000egI0000oM0000VU-1.2d000003 on /Volumes/Produktion (afpfs, nodev, nosuid, mounted by cutter)
afp_4gqctq000egI0000oM0000VU-2.2d000004 on /Volumes/Voyager-5 (afpfs, nodev, nosuid, mounted by cutter)
afp_4gqctq000egI0000oM0000VU-3.2d000005 on /Volumes/Transfer (afpfs, nodev, nosuid, mounted by cutter)

Seemingly relevant System Profile snippets:

  Model Identifier:              MacPro4,1
  Processor Name:                Quad-Core Intel Xeon
  Processor Speed:               2.66 GHz
  Number Of Processors:          2
  Memory:                        8 GB
  Boot ROM Version:              MP41.0081.B03
  SMC Version (system):          1.39f5
  SMC Version (processor tray):  1.39f5

  Type:         afpfs
  Mount Point:  /Volumes/Voyager-5
  Automounted:  No

Info on the server:

Seemingly relevant System Profile snippets:

  Model Identifier:     Xserve1,1
  Processor Name:       Dual-Core Intel Xeon
  Processor Speed:      2.66 GHz
  Number Of Processors: 2
  Boot ROM Version:     XS11.0080.B03
  SMC_version:          1.11f5
  LOM Revision:         1.2.8

Fibre Channel Domain 2:
  Vendor:   LSILogic
  Product:  LSI7404EP
  Revision: Firmware 1.3.14.0
  Speed:    2 Gigabit

SCSI Target Device @ 0:
  Manufacturer: APPLE
  Model:        Xserve RAID
  Revision:     1.50
SCSI Logical Unit @ 0:    
  Capacity:           2,18 TB
  Manufacturer:       APPLE
  Model:              Xserve RAID
  Revision:           1.50
  Mac OS 9 Drivers:   No
  Partition Map Type: APM (Apple Partition Map)
  Volumes:
R_Xraid-Mars:
  Capacity:      2,18 TB
  Writable:      Yes
  File System:   Journaled HFS+
  Mount Point:   /Volumes/R_Xraid-Mars
Stu Thompson
  • 3,339
  • 6
  • 30
  • 47
  • 1
    is anything logged to the console logs around the time the remount occurs? – Dominic D Feb 04 '10 at 17:11
  • @Dominic D: The logs only go back to the last mount ghosting. (An errant daemon was filling up logs. Fixed.) I don't really see anything there. Humph. – Stu Thompson Feb 08 '10 at 13:54
  • I have the same problem with TimeMachine, both, with my MBP and 2 mini's, so this is not an isolated issue. This really pisses me off, because the only way to fix it, is to stop the app (Plex), unmount both shares, and then remount your share. It's a PITA and i would also like to solve this problem... – solefald Apr 18 '10 at 23:15

1 Answers1

1

The cause is likely specific to one of your applications.

For us, it was related to Vectorworks 2008. It's a cross-platform app, and seemed to be keeping its own copy of the current directory in the Save/Open dialog, and not using OS X system facilities for this. We've found other bugs related to unescaped paths before (eg. users put slashes in the filename, this gets interpreted as a path separator, etc).

The steps to reproduce were:

  1. Navigate to server in Vectorworks Open/Save dialog
  2. Quit application
  3. Disconnect from server
  4. Clean up /Volumes and open a Finder window to /Volumes to watch for new ghosts
  5. Start application
  6. Use File > Open and watch a ghost share get created as soon as the Open/Save dialog appears. Note that at this stage we are not connected to the server, so the Open/Save dialog retargets to the user's home directory.

The ghost share that gets created in step 6 has the same number suffix as the last real share, strongly suggesting to us that it's a problem with code internal to the application. Ie. if the last real connection was "Active Projects-4" then the application will create a -4 folder, but actually reconnecting to the server will create a mount point with -5, or whatever.

I'm guessing you'll have to go through trial and error with whatever your mix of apps are. One hint: it was strongly suggested for us to look at Vectorworks when we looked at the contents of those ghost shares. Ours were nested subfolders to one path that usually only contained Vectorworks documents (ie. what you get with mkdir -p /path/to/subfolder).

Ryan McCuaig
  • 111
  • 3