After Yosemite & OS X Server Upgrade: WindowServer Starts Loginwindow/SecurityAgent Processes in a Loop
I decided to upgrade my Mac Mini from Mountain Lion w/ OS X Server 2 to Yosemite w/ OS X Server 4. The Yosemite upgrade went well enough. I proceeded to the Server upgrade and noticed sluggish response shortly afterward. I rebooted - it took minutes to shutdown - and afterwards there was continuing sluggishness. Examining process status (ps -fe) showed a number of loginwindow processes. There was of course the expected 'loginwindow console' with launchd as the parent process - then there were also many unexpected loginwindow processes parented by WindowServer. For each such login process, a SecurityAgent process appeared as well (parented by launchd). Every 15secs, a new loginwindow/SecurityAgent process paie appeared. This accumulated over time. At first I thought I had a damaged disk since, as luck would have it, one member of my two-member RAID disk group just happened to go AWOL, leaving me with a working but 'degraded' RAID device. However, I booted single-user and ran an 'fsck -yf'. No problems reported. I mounted the root filesystem and cleared some caches. Then rebooted and ran a permission repair with Disk Utility. None of this had any impact. At a glance, the disk seems intact in spite of having lost one mirror (after all, RAID 1 is supposed to be resilient to the loss of one mirror). So I don't quite think I can chalk all this off as a disk problem; the coincidental loss of a mirror is more of a red herring. Obviously. something seems to have gone wrong at the point where I upgraded Server, and I of course need to replace the lost mirror. But, mirror replacement aside, I'd like to take a stab at getting a grasp of what exactly happened before I resort to restoring from backups and starting all over (after all, it there is a pitfall I've stumbled into, I could restore and repeat the upgrade only to end up in the same situation). Following is an excerpt of /var/log/system.log that shows messages between two consecutive loginwindow/SecurityAgent process startups in the WindowServer loop. I'm having trouble interpreting this. I would welcome any guidance from someone who knows OS X internals...
Oct 25 23:55:11 hdq.whb-consulting.com loginwindow[619]: Login Window Application Started
Oct 25 23:55:11 hdq.whb-consulting.com WindowServer[161]: _CGXNewConnectionPort: Call from workspace. Updating audit session 100000 -> 100037
Oct 25 23:55:11 hdq.whb-consulting.com DMProxy[620]: CGSCopyDisplayInfoDictionary: error requesting display info dictionary (0x3e8)
Oct 25 23:55:11 hdq.whb-consulting.com WindowServer[161]: CGXSetDisplayColorProfileAndTransfer: Display 0x41dc9d00: Unit 0; ColorProfile { 2049706347 }; TransferFormula (1.000000, 1.000000, 1.000000)
Oct 25 23:55:11 hdq.whb-consulting.com com.apple.AmbientDisplayAgent[214]: AMBD Agent: xpc connection became invalid during event handler
Oct 25 23:55:11 hdq com.apple.xpc.launchd[1] (com.apple.AssistiveControl.running): The HideUntilCheckIn property is an architectural performance issue. Please transition away from it.
Oct 25 23:55:11 hdq com.apple.xpc.launchd[1] (com.apple.UserEventAgent-LoginWindow): This service is defined to be constantly running and is inherently inefficient.
Oct 25 23:55:11 hdq com.apple.xpc.launchd[1] (com.apple.VoiceOver.running): The HideUntilCheckIn property is an architectural performance issue. Please transition away from it.
Oct 25 23:55:11 hdq com.apple.xpc.launchd[1] (com.apple.ZoomWindow.running): The HideUntilCheckIn property is an architectural performance issue. Please transition away from it.
Oct 25 23:55:11 hdq com.apple.xpc.launchd[1] (com.apple.btsa): This key does not do anything: OnDemand
Oct 25 23:55:11 hdq com.apple.xpc.launchd[1] (com.apple.coreservices.lsactivity): Unknown key for Boolean: DrainMessagesAfterFailedInit
Oct 25 23:55:11 hdq com.apple.xpc.launchd[1] (com.apple.helpd): This key does not do anything: OnDemand
Oct 25 23:55:11 hdq com.apple.xpc.launchd[1] (com.apple.noticeboard.agent): This key does not do anything: OnDemand
Oct 25 23:55:11 hdq com.apple.xpc.launchd[1] (com.apple.speech.speechsynthesisd): This key does not do anything: OnDemand
Oct 25 23:55:11 hdq com.apple.xpc.launchd[1] (com.apple.inputswitcher.running): The HideUntilCheckIn property is an architectural performance issue. Please transition away from it.
Oct 25 23:55:11 hdq com.apple.xpc.launchd[1] (com.apple.xpc.launchd.domain.user.loginwindow.619.4294967295): Could not read path: path = /Library/LaunchAgents/com.oracle.java.Java-Updater.plist, error = 2: No such file or directory
Oct 25 23:55:11 hdq.whb-consulting.com ManagedClient[629]: MCX.createConnection bootstrap_register failed = 1100
Oct 25 23:55:11 hdq com.apple.xpc.launchd[1] (com.apple.universalaccesscontrol.running): The HideUntilCheckIn property is an architectural performance issue. Please transition away from it.
Oct 25 23:55:11 hdq com.apple.xpc.launchd[1] (com.apple.universalaccessd.running): The HideUntilCheckIn property is an architectural performance issue. Please transition away from it.
Oct 25 23:55:11 hdq com.apple.xpc.launchd[1] (com.apple.xpc.launchd.domain.system): Service "com.apple.xpc.launchd.unmanaged.ManagedClient.629" tried to hijack endpoint "com.apple.mcxd" from owner: com.apple.xpc.launchd.unmanaged.ManagedClient.226
Oct 25 23:55:11 hdq.whb-consulting.com ManagedClient[629]: ManagedClient - Unable to create the connection
Oct 25 23:55:11 hdq.whb-consulting.com ManagedClient[629]: ManagedClient- runloop could not be started; status = -2
Oct 25 23:55:11 hdq.whb-consulting.com WindowServer[161]: _CGXNewConnectionPort: Call from workspace. Updating audit session 100037 -> 100037
Oct 25 23:55:11 hdq com.apple.xpc.launchd[1] (com.apple.DataDetectorsDynamicData): The JoinExistingSession key is only available to Application services.
Oct 25 23:55:11 hdq com.apple.xpc.launchd[1] (com.apple.appkit.xpc.sandboxedServiceRunner): The JoinExistingSession key is only available to Application services.
Oct 25 23:55:11 hdq.whb-consulting.com loginwindow[619]: Login Window Started Security Agent
Oct 25 23:55:11 hdq.whb-consulting.com com.apple.SecurityServer[55]: Session 100037 created
Oct 25 23:55:11 hdq askpermissiond[622]: objc[622]: Class FALogging is implemented in both /System/Library/PrivateFrameworks/FamilyCircle.framework/Versions/A/FamilyCircl e and /System/Library/PrivateFrameworks/FamilyNotification.framework/Versions/A/Famil yNotification. One of the two will be used. Which one is undefined.
Oct 25 23:55:12 hdq.whb-consulting.com WindowServer[161]: 3891612: App SecurityAgent cannot order in untagged windows before login.
Oct 25 23:55:12 hdq.whb-consulting.com WindowServer[161]: WSOrderWinsAndPanels: error ordering window
Oct 25 23:55:12 hdq.whb-consulting.com askpermissiond[622]: StoreTransport: Resetting APS Connection using environment name production
Oct 25 23:55:12 hdq.whb-consulting.com UserEventAgent[621]: Failed to copy info dictionary for bundle /System/Library/UserEventPlugins/alfUIplugin.plugin
Oct 25 23:55:12 hdq.whb-consulting.com WiFiAgent[628]: [NO client logger] <Sep 9 2014 16:12:26> WIFICLOUDSYNC WiFiCloudSyncEngineCreate: created...
Oct 25 23:55:12 hdq.whb-consulting.com WiFiAgent[628]: [NO client logger] <Sep 9 2014 16:12:26> WIFICLOUDSYNC WiFiCloudSyncEngineRegisterCallbacks: WiFiCloudSyncEngineCallbacks version - 0, bundle id - com.apple.wifi.WiFiAgent
Oct 25 23:55:12 hdq.whb-consulting.com WiFiAgent[628]: securityd_message_with_reply_sync Failed to talk to secd after 4 attempts.
Oct 25 23:55:12 hdq.whb-consulting.com UserEventAgent[621]: user agent networkd: built Sep 9 2014 16:11:57
Oct 25 23:55:13 hdq com.apple.xpc.launchd[1] (com.apple.xpc.launchd.domain.system): Caller not allowed to perform action: SecurityAgent.630, action = legacy spawn, code = 1: Operation not permitted, uid = 92, euid = 92, gid = 92, egid = 92, asid = 100037
Oct 25 23:55:13 hdq.whb-consulting.com SecurityAgent[630]: spawn_via_launchd() failed, errno=1 label=[0x0-0x62062].com.apple.AppleSpell path=/System/Library/Services/AppleSpell.service/Contents/MacOS/AppleSpell flags=0 : LaunchApplicationClient.cp #963 LaunchApplicationWithSpawnViaLaunchD() q=NSTextCheckingOperationQueue :: NSOperation 0x7ff033612f80 (QOS: USER_INITIATED)
Oct 25 23:55:13 hdq.whb-consulting.com SecurityAgent[630]: spawn_via_launchd() failed, errno=1 label=[0x0-0x62062].com.apple.AppleSpell path=/System/Library/Services/AppleSpell.service/Contents/MacOS/AppleSpell flags=0
Oct 25 23:55:13 hdq.whb-consulting.com SecurityAgent[630]: Error launching spell checker for Multilingual: Error Domain=NSCocoaErrorDomain Code=256 "The application “AppleSpell” could not be launched because a miscellaneous error occurred (OSStatus -10810)." UserInfo=0x7ff0335d4100 {NSURL=file:///System/Library/Services/AppleSpell.service/, NSLocalizedDescription=The application “AppleSpell” could not be launched because a miscellaneous error occurred (OSStatus -10810)., NSUnderlyingError=0x7ff0335d55f0 "The operation couldn’t be completed. (OSStatus error -10810.)"}
Oct 25 23:55:13 hdq com.apple.xpc.launchd[1] (com.apple.coreservices.appleid.authentication[604]): Service exited due to signal: Killed: 9
Oct 25 23:55:16 hdq.whb-consulting.com BezelServices 245.23[619]: ASSERTION FAILED: dvcAddrRef != ((void *)0) -[DriverServices getDeviceAddress:] line: 2602
Oct 25 23:55:18 --- last message repeated 1 time ---
Oct 25 23:55:18 hdq.whb-consulting.com emond[634]: SetUpLogs: uid = 0 gid = 0
Oct 25 23:55:18 hdq.whb-consulting.com emond[634]: SetUpLogs: opening /Library/Logs/EventMonitor/EventMonitor.error.log
Oct 25 23:55:18 hdq com.apple.xpc.launchd[1] (com.apple.emond): Service only ran for 0 seconds. Pushing respawn out by 10 seconds.
Oct 25 23:55:23 hdq.whb-consulting.com nsurlstoraged[208]: realpath() returned NULL for /var/root/Library/Caches/$(CFBundleIdentifier)
Oct 25 23:55:23 hdq.whb-consulting.com nsurlstoraged[208]: The read-connection to the DB=/var/root/Library/Caches/$(CFBundleIdentifier)/Cache.db is NOT valid. Unable to determine schema version.
Oct 25 23:55:23 hdq.whb-consulting.com nsurlstoraged[208]: realpath() returned NULL for /var/root/Library/Caches/$(CFBundleIdentifier)
Oct 25 23:55:23 --- last message repeated 1 time ---
Oct 25 23:55:23 hdq.whb-consulting.com nsurlstoraged[208]: ERROR: unable to determine file-system usage for FS-backed cache at /var/root/Library/Caches/$(CFBundleIdentifier)/fsCachedData. Errno=13
Oct 25 23:55:23 hdq.whb-consulting.com AppleIDAuthAgent[623]: AppleIdAuth URL: https://identity.apple.com/dsservices/dsxmlrpc
Oct 25 23:55:26 hdq.whb-consulting.com WindowServer[161]: Session 272 retained (2 references)
Oct 25 23:55:26 hdq.whb-consulting.com WindowServer[161]: Session 272 released (1 references)
Oct 25 23:55:26 hdq.whb-consulting.com loginwindow[637]: Login Window Application Started
PowerBook, Mac-Mini, Mac OS X (10.4.10)