Server Connections Interrupted

To DJ GiNSU,

Sorry for the delayed response from last week. I went and performed some additional testing with the Time Capsule - just to be sure that I was not somehow getting the disconnect error behind the scenes and possibly not noticing it.

The only disconnect "errors" that I am seeing is when the Mac (any of my Macs) wakes from sleep while the Time Capsule share is mounted. I don't see the sequence of errors at any other time.

It does appear that that the share needs to be mounted for longer than an hour or so - for the errors to appear on wake from sleep - basically if I tell the Mac to sleep - and then wake it soon after - I don't get the AFP reconnect messages. I'm not sure if it is the amount of time the Mac has been sleeping - or the amount of time the mounted share has been sitting idly mounted.

As an additional test - and to satisfy my curiosity as well as to somewhat prove that this sequence of AFP messages on wake appears to be "normal behavior" (although a bit disconcerting) - I performed identical testing using my Western Digital MyBookLive drive - which supports AFP - and I saw the same multiple AFP reconnection attempts using the WD drive - without the Time Capsule even being in the picture. There was even the "Found 1 Filesystem(s) with problems" message with the WD as well.

The frequency of AFP messages appearing after wake - was slightly less with the WD drive than with the Time Capsule - but nevertheless - the same sequence of messages was occuring with both drives.

I also performed the testing both with Time Machine enabled and disabled. The Time Machine being enabled/disabled - did not change the AFP messages.

During my testing - I had discovered that my MacBook Air had a shared mounted on the Time Capsule - for almost 10 days - and had gone to sleep and was put aside. During that time frame - I actually updated the firmware on the Time Capsule to 7.6.3 - and rebooted the Time Capsule at least once. To my surprise - upon waking the MacBook Air - it reconnected to the time capsule share - basically seamlessly - although there were 5 or 6 reconnect attempts - the MacBook Air seemed to have no issue with the Time Capsule disappearing while the Mac had been sleeping. I really thought that it would have had trouble recovering in this scenario.

I really believe that this is a Mac OS X issue in handling of AFP and not necessarily a problem with the 7.6.x firmware.

Hopefully people will find this info useful. I'm not sure how much time I can continue to spend on this.

~Scott

tessmar wrote:

.....

TC was created not as a general NAS but specifically as a backup device. In fact, Apple's sales material including the product information on the web site never mentions any other use for it (other than, of course, as a WiFi router).

Actually, on my Time Capsule's box there is written: "3TB of file storage for any computer on your network" or something like this.

I found this post as I started having the same pop-up error yesterday after I installed and configured Netatalk. I have a slightly different set-up.

Linux server running Netatalk 3.0.2

Ethernet connection to the server.

iMac 10.8.2

While I copy or read data from the server, there is no pop-up. As soon as the network connection is idle the pop-ups start.

I didn't have any pop-ups for quite a while. I think this is because mdworker (Spotlight) was indexing my shared folder on the server. So I stopped Spotlight from indexing the two shared folders on the server. Now I see mdworker giving an error.

At the moment I have VLC playing something in the background. VLC (probably any other app reading from the server) stops the OSX idle and so stops the dialog box from showing up.

From the console:

Feb 17 11:42:54 VLC[2773]: kIOPMAssertionTypePreventUserIdleSystemSleep

Feb 17 11:46:32 mdworker[3221]: Unable to talk to lsboxd

Feb 17 11:46:32 mdworker[3220]: Unable to talk to lsboxd

Feb 17 11:46:33 kernel[0]: Sandbox: sandboxd(3222) deny mach-lookup com.apple.coresymbolicationd

Feb 17 11:46:33 sandboxd[3222] ([3221]): mdworker(3221) deny mach-lookup com.apple.ls.boxd

Feb 17 11:46:33 sandboxd[3222] ([3220]): mdworker(3220) deny mach-lookup com.apple.ls.boxd

Feb 17 11:47:33 mdworker[3228]: Unable to talk to lsboxd

Feb 17 11:47:33 mdworker[3229]: Unable to talk to lsboxd

Feb 17 11:47:33 sandboxd[3230] ([3228]): mdworker(3228) deny mach-lookup com.apple.ls.boxd

Feb 17 11:47:33 sandboxd[3230] ([3229]): mdworker(3229) deny mach-lookup com.apple.ls.boxd

Feb 17 11:47:34 kernel[0]: Sandbox: sandboxd(3230) deny mach-lookup com.apple.coresymbolicationd

Feb 17 11:49:34 mdworker[3237]: Unable to talk to lsboxd

Feb 17 11:49:34 mdworker[3236]: Unable to talk to lsboxd

Feb 17 11:49:34 sandboxd[3238] ([3237]): mdworker(3237) deny mach-lookup com.apple.ls.boxd

Feb 17 11:49:34 sandboxd[3238] ([3236]): mdworker(3236) deny mach-lookup com.apple.ls.boxd

Feb 17 11:49:34 kernel[0]: Sandbox: sandboxd(3238) deny mach-lookup com.apple.coresymbolicationd

I suspect that the OS does some sort of system sleep for the network. This causes a temporary disconnect to the server (or connected drive) that then causes the dialog box to pop-up.

Are you getting the same messages in the console??

I have not seen anything like this (something preventing the system from sleeping). Nor have I seen the popup messages again since designating the TC as my Time Machine and making sure I manually disconnect and eject the share and device when not actually reading or writing it. My Macbook Pro is still on 10.7.5.

I just got a second laptop and it of course came with 10.8.2 installed. I did designate the TC as the backup for it, but plan to do some additional investigation to see if the errors only occur on the 10.7.5 machine. To do that I will have to change the new machine temporarily to point at an external usb drive as the Time Machine so that the setup is the same as it was when I started seeing the problem.

Again, though I became aware of an issue after a power outage in December, it is possible the errors (but not the popup) had been going for an indeterminate time before that. Since I was neither monitoring the Console logs nor "tuning in" on when and how the TC was spinning up there is no way for me to know.

To Nuke -

Looks like you are getting a lot of Sandbox messages. I get these as well - for a variety of reasons. They seem to occurs on clean installs on Mountain Lion as well. Not sure which ones are serious and which ones are not. I was able to significantly reduce the volume of the very repetive lsboxd and sandboxd messages - by doing a safe boot - waiting a few minutes - logging in - waiting a few minutes - and then shutting down - with a normal power on. To do the safe boot - restart the Mac - and then hold down left shift key as soon as you hear the startup chime - continuing to hold the left shift key down until you see a gray progress bar on the botton of the screen. You will then see a red Safe Boot indicator on the login screen. You will notice slowness during boot up and log in - potentially as well as during shutdown. Let the Mac sit during each of these phases to do whatever cleanup that it decides it wants to do (wait 5 min at login screen - then wait 5 min at desktop after login - then shutdown - don't run anything while in safe boot mode).

I don't believe the sandbox errors have anything to do with the Time Capsule issues - but at least the safe boot should reduce them. There seem to be quite a few apps that aren't fully sandbox compliant - including some of Apple's own OS X code - especially with iCloud - at least that is mostly where I see the sandbox errors.

~Scott

I've implemented a sleepwatcher script that unmounts my time capsule volume when the machine goes to sleep, and remounts it when my machine wakes up. This, also, doesn't work. It just prolongs the inevitable.

This series of junk shows up in my Mac's syslog every 5 minutes, pretty much whenever the Time Capsule doesn't feel like cooperating any more and continues to fill up my log files, slow my machine down, and generally make the volume too slow to use.

Feb 25 19:03:57 Cameron kernel[0] <Debug>: AFP_VFS afpfs_DoReconnect started /Volumes/vault prevTrigger 27 currTrigger 28

Feb 25 19:03:57 Cameron kernel[0] <Debug>: AFP_VFS afpfs_DoReconnect: doing reconnect on /Volumes/vault

Feb 25 19:03:57 Cameron kernel[0] <Debug>: AFP_VFS afpfs_DoReconnect: posting to KEA EINPROGRESS for /Volumes/vault

Feb 25 19:03:57 Cameron kernel[0] <Debug>: AFP_VFS afpfs_DoReconnect: Max reconnect time: 600 secs, Connect timeout: 15 secs for /Volumes/vault

Feb 25 19:03:57 Cameron kernel[0] <Debug>: AFP_VFS afpfs_DoReconnect: connect to the server /Volumes/vault

Feb 25 19:03:57 Cameron.local KernelEventAgent[44] <Notice>: tid 00000000 found 1 filesystem(s) with problem(s)

Feb 25 19:03:57 Cameron.local KernelEventAgent[44] <Notice>: tid 00000000 received event(s) VQ_NOTRESP (1)

Feb 25 19:03:57 Cameron kernel[0] <Debug>: AFP_VFS afpfs_DoReconnect: Logging in with uam 13 /Volumes/vault

Feb 25 19:03:57 Cameron kernel[0] <Debug>: AFP_VFS afpfs_DoReconnect: Restoring session /Volumes/vault

Feb 25 19:03:57 Cameron kernel[0] <Debug>: AFP_VFS afpfs_DoReconnect: get the reconnect token

I have TWO time capsules that exhibit this behavior - and it does it on ALL of my Macs. Apple's support told me I could mount the volume and use it to store my music library - I'd just have to mount it before I want to use it. The box says "Save data on the 2 terabyte internal hard-drive wirelessly from any computer on the network". It doesn't say I have to use time machine. It works like it's supposed to for a short period of time, and then decides one day "I don't feel like doing this any more", and begins to behave like the no-name-brands I dumped specifically so I wouldn't have to deal with problems like this.

The ONLY thing it works as, is a time machine backup disk. Apple's support has been of no help at all, and I'm frankly sick of dealing with it. If anyone figures out how to make this thing work as advertised, I'm all ears. But I'm about one more AFP tempter tantrum away from shoving this down the genius bar's throat.

If you have a time capsule, and are experiencing "server disconnected" error messages after having file shares open for long periods of time, PLEASE submit a bug report.

http://www.apple.com/feedback/timecapsule.html

Even if you aren't experiencing server disconnected error messages - if you could plug a USB drive into your time capsule, connect to it through finder, and wait 24 hours, then open terminal and run:

sudo syslog -w 300

I suspect you will see the afpfs_DoReconnect messages are appearing every 5 minutes. This is definitely a bug in the TC firmware, not 'normal behavior', as the Apple support tech said it was, and should be elevated as the product does not do what the box says it does.

I gave up. This is annoying, 7.6.x firmware is a piece of trash. For about a year(!) Apple could not fix an obvious bug with TC freeze after disk wireless access via SMB/Windows. Now these reconnects with AFP...

My TimeCapsule went back to its box. Installed non-Apple wifi router + Synology NAS. Everything is rock solid and stable. Not sure about Synology's implementation of TimeMachine (I don't use it) but as a shared disk it works just fine. Bye-bye TimeCapsule. I wish Apple hire more experienced developers for creating firmware for their network devices.

Solundir -

I too am frustrated. PLEASE submit a bug report at http://www.apple.com/feedback/timecapsule.html and note that tech support said the behavior is 'normal' and did not help you. We need more than just a handful of complaints for them to look into the problem.

I'm getting this behaviour too.

I have an airport extreme base station with a USB drive hooked to it. It doesn't matter what type of USB drive because the issue has occured with different types.

I have my iTunes library on the USB drive. It's a large library - 163ish gigs.

I'm seeing the disconnect message in the mornings when I wake the computer up. Offhand I can't recall if I see it at other times as well.

I never experience any issues as far as not being able to connect to the drive - the requester simply pops up.

So, the issue isn't specifically limited to Timecapsule.

More information.

I happened to be sitting at my computer early this morning.

I've got Carbon Copy Cloner set up to perform a backup once a day FROM the USB drive connected to the Airport Extreme Base Station To an external drive connected to the mac.

The instant this backup started, the Disconnect message popped up. The backup completed successfully and no errors were observed other than this requester.

Maybe this is a clue.

Where and how are you seeing the message: 1) in a popup or 2) in the console logs? Also, what OS version are yoou running and on what computer?

I just saw the popup for a second when I woke the computer up this morning...first time in several weeks. It disappeared in an instant and has not recurred.

It is useful to hear that you have seen it and do not have a Time Capsule. SBeattie and I suspect that the message can occur as part of a normal process as well as part of an abnormal situation, which makes it very difficult to isolate in terms of causes and impact.

A single instance of the popup or notation in the log, partcularly upon wake is not, we believe, something to worry about and may just be a minor timing issue between the OS and other components such as WiFi or the Time Capsule.

However, a situation where the TC, with or without the popup, partially spins up and stops over and over again in conjunction with what appears as an infinite loop of disconnects and reconnect sequences in the log cannot be, in our opinions, normal or healthy for the drive.

But your observation does add value to the discussion by verifying that the notification is not necessarily exclusive to the TC, and does point back to the OS being the most likely source of the issue, though compounded in the case of interaction with the TC by the control mechanisms such as firmware in that device.

Same issue here. 2011 Mac Mini; 10.8.2. Tried reverting back to 7.5.2, but it's starting to do the same thing again. A reboot tends to fix it, but this stanza below keeps repeating in the syslog:

3/14/13 6:03:58.000 AM kernel[0]: AFP_VFS afpfs_DoReconnect started /Volumes/Data prevTrigger 135783 currTrigger 135784

3/14/13 6:03:58.000 AM kernel[0]: AFP_VFS afpfs_DoReconnect: doing reconnect on /Volumes/Data

3/14/13 6:03:58.000 AM kernel[0]: AFP_VFS afpfs_DoReconnect: soft mounted and hidden volume so do not notify KEA for /Volumes/Data

3/14/13 6:03:58.000 AM kernel[0]: AFP_VFS afpfs_DoReconnect: Max reconnect time: 30 secs, Connect timeout: 15 secs for /Volumes/Data

3/14/13 6:03:58.000 AM kernel[0]: AFP_VFS afpfs_DoReconnect: connect to the server /Volumes/Data

3/14/13 6:03:58.000 AM kernel[0]: ASP_TCP asp_SetTCPQoS: sock_settclassopt got error 57

3/14/13 6:03:58.000 AM kernel[0]: AFP_VFS afpfs_DoReconnect: Logging in with uam 10 /Volumes/Data

3/14/13 6:03:58.000 AM kernel[0]: AFP_VFS afpfs_DoReconnect: Restoring session /Volumes/Data

3/14/13 6:03:58.000 AM kernel[0]: AFP_VFS afpfs_DoReconnect: get the reconnect token

3/14/13 6:03:58.000 AM kernel[0]: ASP_TCP Disconnect: triggering reconnect by bumping reconnTrigger from curr value 135784 on so 0xffffff806a956810

3/14/13 6:03:58.000 AM kernel[0]: ASP_TCP asp_tcp_usr_control: invalid kernelUseCount 0

I also see the AFP disconnect/reconnect happening at a relatively frequent rate in the Airport Utility log monitor when this behavior is going on.

I'm guessing that there's an issue with the AFP protocol in 10.8 that needs to be fixed. The only thing I've found that fixes it short term for me is a reboot. Tried completely wiping out my TC backups and putting them in again, tried reloading OS X, so I'm pretty much at my wit's end with this bug. I also noticed that it tends to lock up Finder when browing other volumes for files when it happens.

All other disks are fine (used SMART utility to verify). It's definitely an OS issue.

I sent an email to Tim Cook, which was forwarded to executive affairs. I will be speaking with someone a little higher in the food chain than tech support tomorrow.

Tessmar -

The pop-up 'server disconnected' will only show up after the problem has gotten so bad that the OS cant recover from the disconnects every five minutes. The syslog utility shows a stream of errors long before the degradation is bad enough to cause the popup. AFP is a pretty robust protocol, which usually recovers. If you use CIFS instead of AFP, you will find that it just outright crashes after twenty hours connected, the session just crashes instead of logging disconnects. In either case, its a major problem.