Logging out and in on OS X takes 4-5 minutes?

I've got a 3.4 GHz i7 iMac (8 cores) with 24 GB of RAM. (2 16 GB chips plus 2 4 GB chips.) I know this amount of RAM is "officially unsupported" which is why I mention it.

Lately logging out (to restart into boot camp) takes 4 or 5 minutes, and logging back in does as well. When logging out, the Finder disappears and it goes to the gray screen that you see just before it restarts... but then sits there for 4-5 minutes. When logging in, you see the "enter user name / password" screen with the spinning progress indicator... which again takes 4-5 minutes.

Is it copying all 24GB of RAM to disk, and restoring it, to re-open windows in saved states or something like that? If not what? I reboot into boot camp fairly often for work and this is ridiculous.

Posting console log from when I think I logged in this morning:

6/4/13 11:19:59.491 AM WindowServer[277]: Created shield window 0x12 for display 0x003f003d
6/4/13 11:19:59.491 AM WindowServer[277]: handle_will_sleep_auth_and_shield_windows: no lock state data
6/4/13 11:19:59.491 AM WindowServer[277]: Created shield window 0x13 for display 0x003f003e
6/4/13 11:19:59.491 AM WindowServer[277]: handle_will_sleep_auth_and_shield_windows: no lock state data
6/4/13 11:19:59.491 AM WindowServer[277]: Created shield window 0x14 for display 0x003f003f
6/4/13 11:19:59.491 AM WindowServer[277]: handle_will_sleep_auth_and_shield_windows: no lock state data
6/4/13 11:19:59.501 AM WindowServer[277]: Created shield window 0x15 for display 0x003f0040
6/4/13 11:19:59.501 AM WindowServer[277]: handle_will_sleep_auth_and_shield_windows: no lock state data
6/4/13 11:19:59.000 AM kernel[0]: The USB device Dell USB Keyboard (Port 3 of Hub at 0xfa100000) may have caused a wake by issuing a remote wakeup (3)
6/4/13 11:19:59.000 AM kernel[0]: HID tickle 247 ms
6/4/13 11:20:00.000 AM kernel[0]: AppleBCM5701::selectMedium - autoselect, any duplex, EEE allowed, flow control allowed
6/4/13 11:20:00.000 AM kernel[0]: Ethernet [AppleBCM5701Ethernet]: Link down on en0
6/4/13 11:20:00.475 AM hidd[46]: MultitouchHID: device bootloaded
6/4/13 11:20:00.950 AM mDNSResponderHelper[7757]: do_mDNSInterfaceAdvtIoctl: ioctl call SIOCGIFINFO_IN6 failed - error (22) Invalid argument
6/4/13 11:20:00.951 AM mDNSResponderHelper[7757]: do_mDNSInterfaceAdvtIoctl: ioctl call SIOCGIFINFO_IN6 failed - error (22) Invalid argument
6/4/13 11:20:04.000 AM kernel[0]: Ethernet [AppleBCM5701Ethernet]: Link up on en0, 1-Gigabit, Full-duplex, Asymmetric Receiving flow-control, Debug [796d,2301,0de1,0300,c9e1,3800]
   6/4/13 11:20:06.612 AM digest-service[7212]: digest-request: uid=0
6/4/13 11:20:06.612 AM digest-service[7212]: digest-request: init request
6/4/13 11:20:06.613 AM digest-service[7212]: digest-request: init return domain: CSMC server: AWMA047LB
 6/4/13 11:20:06.616 AM configd[17]: network changed: v4(en0+:10.223.233.133) DNS+ Proxy+ SMB+
6/4/13 11:20:06.624 AM configd[17]: setting hostname to "vernmac.csmc.edu"
6/4/13 11:20:07.314 AM nsupdate[7767]: krb5_sendto_context is called on main thread, its a blocking api
6/4/13 11:20:07.438 AM nsupdate[7772]: krb5_sendto_context is called on main thread, its a blocking api
 6/4/13 11:20:07.720 AM SymMissedTask - parent[258]: sleeptime recorded: Tue Jun  4 03:31:00 2013
6/4/13 11:20:07.720 AM SymMissedTask - parent[258]: waketime is: Tue Jun  4 11:20:07 2013
6/4/13 11:20:07.721 AM prl_naptd[301]: Reloading configuration...
6/4/13 11:20:07.741 AM prl_naptd[301]: vnic0: DHCP/NAT for 10.211.55.1-10.211.55.254 netmask 255.255.255.0
6/4/13 11:20:07.741 AM prl_naptd[301]: vnic1: DHCP for 10.37.129.1-10.37.129.254 netmask 255.255.255.0
6/4/13 11:20:08.619 AM mDNSResponderHelper[7757]: do_mDNSInterfaceAdvtIoctl: ioctl call SIOCGIFINFO_IN6 failed - error (22) Invalid argument
6/4/13 11:20:08.620 AM mDNSResponderHelper[7757]: do_mDNSInterfaceAdvtIoctl: ioctl call SIOCGIFINFO_IN6 failed - error (22) Invalid argument
6/4/13 11:20:10.295 AM SecurityAgent[314]: User info context values set for jensenv
6/4/13 11:20:10.556 AM configd[17]: network changed: v4(en0:10.223.233.133) DNS! Proxy SMB
6/4/13 11:20:10.657 AM awacsd[56]: Connecting AWACS client: 1462471710.p14.members.btmm.icloud.com.
6/4/13 11:20:10.685 AM SecurityAgent[314]: Login Window login proceeding
6/4/13 11:20:11.000 AM kernel[0]: Sandbox: kcm(7797) deny mach-lookup com.apple.networkd
6/4/13 11:20:12.000 AM kernel[0]: utun_ctl_connect: creating interface utun1
6/4/13 11:20:12.100 AM acvpnagent[62]: Function: if_get_interfaces File: Utility/if_unix.cpp Line: 186 Invoked Function: ioctl Return Code: -1 (0xFFFFFFFF) Description: unknown (SIOCGIFDSTADDR) for interface "utun1"
6/4/13 11:20:12.000 AM kernel[0]: utun1: attached with 0 suspended link-layer multicast membership(s)
6/4/13 11:20:12.861 AM nsupdate[7806]: krb5_sendto_context is called on main thread, its a blocking api
6/4/13 11:20:13.568 AM ntpd[232]: unable to create socket on utun1 (32) for fd00:6587:52d7:10c1:21df:f66e:e232:369a#123
6/4/13 11:20:14.422 AM netbiosd[147]: name servers down?
6/4/13 11:20:14.498 AM CVMServer[178]: Check-in to the service com.apple.cvmsCompAgent_x86_64 failed. This is likely because you have either unloaded the job or the MachService has the ResetAtClose attribute specified in the launchd.plist. If present, this attribute should be removed.
6/4/13 11:20:14.503 AM loginwindow[41]: Login Window - Returned from Security Agent
6/4/13 11:20:14.522 AM CVMServer[178]: Check-in to the service com.apple.cvmsCompAgent_x86_64 failed. This is likely because you have either unloaded the job or the MachService has the ResetAtClose attribute specified in the launchd.plist. If present, this attribute should be removed.
6/4/13 11:20:14.543 AM loginwindow[41]: ERROR | ScreensharingLoginNotification | Failed sending message to screen sharing GetScreensharingPort, err: 1102
6/4/13 11:20:15.119 AM nsupdate[7853]: krb5_sendto_context is called on main thread, its a blocking api
6/4/13 11:20:15.793 AM com.apple.launchd[1]: (com.apple.smb.preferences) Throttling respawn: Will start in 1 seconds
6/4/13 11:20:15.793 AM com.apple.launchd[1]: (com.apple.smb.preferences) Throttling respawn: Will start in 1 seconds
6/4/13 11:20:15.904 AM com.apple.launchd[1]: (com.apple.smb.preferences) Throttling respawn: Will start in 1 seconds
6/4/13 11:20:16.909 AM digest-service[7212]: digest-request: uid=0
6/4/13 11:20:16.909 AM digest-service[7212]: digest-request: init request
6/4/13 11:20:16.910 AM digest-service[7212]: digest-request: init return domain: CSMC server: AWMA047LB
6/4/13 11:20:18.458 AM nsupdate[7871]: krb5_sendto_context is called on main thread, its a blocking api
6/4/13 11:20:20.193 AM nsupdate[7883]: krb5_sendto_context is called on main thread, its a blocking api
6/4/13 11:20:25.989 AM netbiosd[147]: name servers down?
6/4/13 11:20:27.728 AM NortonMissedTask - Child #0[7919]: About to launch child 0
6/4/13 11:20:34.699 AM apsd[58]: Unable to bootstrap_lookup connection port for 'com.apple.CalendarAgent.push': Unknown service name
6/4/13 11:20:34.699 AM apsd[58]: Unable to bootstrap_lookup connection port for 'com.apple.syncdefaultsd.push': Unknown service name
6/4/13 11:20:34.699 AM apsd[58]: Unable to bootstrap_lookup connection port for 'com.apple.safaridavclient.push': Unknown service name
6/4/13 11:20:34.699 AM apsd[58]: Unable to bootstrap_lookup connection port for 'com.apple.ubd.system-push': Unknown service name
6/4/13 11:20:34.700 AM apsd[58]: Unable to bootstrap_lookup connection port for 'com.apple.AddressBook.PushNotification': Unknown service name
6/4/13 11:20:34.700 AM apsd[58]: Unable to bootstrap_lookup connection port for 'com.apple.AOSPushRelay.push': Unknown service name
6/4/13 11:20:37.721 AM com.apple.backupd-helper[7780]: Not starting scheduled Time Machine backup - time machine destination not resolvable.
6/4/13 11:22:11.562 AM netbiosd[147]: name servers down?
6/4/13 11:23:29.894 AM loginwindow[41]: USER_PROCESS: 41 console
6/4/13 11:23:30.023 AM com.apple.launchd[1]: (com.realvnc.vncserver_agent[419]) Exited with code: 4
6/4/13 11:23:30.108 AM com.apple.launchd.peruser.573771919[622]: (com.spotify.webhelper) Unknown key: SpotifyPath
6/4/13 11:23:30.108 AM com.apple.launchd.peruser.573771919[622]: (com.apple.gamed) Ignored this key: UserName
6/4/13 11:23:30.108 AM com.apple.launchd.peruser.573771919[622]: (com.apple.gamed) Ignored this key: GroupName
6/4/13 11:23:30.109 AM com.apple.launchd.peruser.573771919[622]: (com.apple.ReportCrash) Falling back to default Mach exception handler. Could not find: com.apple.ReportCrash.Self
6/4/13 11:23:30.112 AM loginwindow[41]: Connection with distnoted server was invalidated
6/4/13 11:23:30.320 AM loginwindow[41]: lwMountWithArrayOfPaths: Skipping mount, final urlString was NULL
6/4/13 11:23:31.190 AM blued[55]: kBTXPCUpdateUserPreferences gConsoleUserUID = 573771919
6/4/13 11:23:32.272 AM WindowServer[277]: **DMPROXY** (2) Found `/System/Library/CoreServices/DMProxy'.
6/4/13 11:23:32.563 AM WindowServer[277]: Display 0x042801c0: MappedDisplay Unit 0; ColorProfile { 2, "iMac"}; TransferFormula (1.000000, 1.000000, 1.000000)
6/4/13 11:23:33.353 AM com.apple.launchd.peruser.573771919[622]: (com.apple.afpstat-qfa[8767]) Exited with code: 2
6/4/13 11:23:33.975 AM prl_naptd[8770]: Starting Parallels Network Daemon
6/4/13 11:23:34.000 AM kernel[0]: CODE SIGNING: cs_invalid_page(0x1000): p=8773[GoogleSoftwareUp] clearing CS_VALID
6/4/13 11:23:35.880 AM talagent[8734]: _LSSetApplicationInformationItem(kLSDefaultSessionID, asn, _kLSApplicationIsHiddenKey, hidden ? kCFBooleanTrue : kCFBooleanFalse, NULL) produced OSStatus -50 on line 623 in TCApplication.m
6/4/13 11:23:35.880 AM talagent[8734]: _LSSetApplicationInformationItem(kLSDefaultSessionID, asn, TAL_kLSIsProxiedForTALKey, kCFBooleanTrue, NULL) produced OSStatus -50 on line 626 in TCApplication.m
6/4/13 11:23:38.010 AM ScanNotification[8780]: /Library/Preferences/com.symantec.schedScanResults not found as directory.
6/4/13 11:23:38.015 AM SymSecondaryLaunch[8781]: launch for id = 2      event = oapp result = 0
6/4/13 11:23:38.016 AM com.apple.launchd.peruser.573771919[622]: (com.apple.mrt.uiagent[8757]) Exited with code: 255
6/4/13 11:23:41.440 AM UserEventAgent[8719]: cannot find fw daemon port 1102
6/4/13 11:23:42.790 AM WindowServer[277]: CGXDisableUpdate: UI updates were forcibly disabled by application "SystemUIServer" for over 1.00 seconds. Server has re-enabled them.
6/4/13 11:23:43.667 AM appleprofilepolicyd[8807]: appleprofilepolicyd: profiling drivers not loaded, loading
6/4/13 11:23:43.867 AM WindowServer[277]: reenable_update_for_connection: UI updates were finally reenabled by application "SystemUIServer" after 2.08 seconds (server forcibly re-enabled them after 1.00 seconds)
6/4/13 11:23:44.436 AM sudo[8811]:     root : TTY=unknown ; PWD=/ ; USER=jensenv ; COMMAND=/bin/launchctl load /Library/LaunchAgents/com.parallels.vm.prl_pcproxy.plist
6/4/13 11:23:44.000 AM kernel[0]: NTFS volume name LACIEWIN, version 3.1.
6/4/13 11:23:44.942 AM NetworkBrowserAgent[8817]: Starting NetworkBrowserAgent
6/4/13 11:23:45.121 AM sudo[8823]:     root : TTY=unknown ; PWD=/ ; USER=jensenv ; COMMAND=/bin/launchctl start com.parallels.vm.prl_pcproxy
6/4/13 11:23:52.787 AM netbiosd[147]: name servers down?
6/4/13 11:23:52.989 AM mdmclient[8758]: [Agent:573771919] Processing server request: ProfileList  for: <User: 573771919>
6/4/13 11:24:05.094 AM LKDCHelper[8897]: Starting (uid=573771919)
6/4/13 11:24:14.638 AM com.apple.time[8719]: Interval maximum value is 946100000 seconds (specified value: 9223372036854775807).
6/4/13 11:24:14.639 AM com.apple.time[8719]: Interval maximum value is 946100000 seconds (specified value: 9223372036854775807).
6/4/13 11:24:14.936 AM com.apple.backupd[8783]: Starting automatic backup
6/4/13 11:24:21.691 AM com.apple.backupd[8783]: Backing up to: /Volumes/TimeMachine/Backups.backupdb
6/4/13 11:24:23.776 AM CalendarAgent[8764]: [com.apple.calendar.store.log.exchange.queue] [error = Error Domain=CalExchangeErrorDomain Code=-4 "Calendar can’t save the event “Developer Meeting” to the Exchange server." UserInfo=0x7fcf5bd07490 {NSLocalizedFailureReason=The account "Cshs" currently can’t be modified. To discard your changes and continue using the version of your calendars that’s on the server, click Revert to Server., CalFailedOperationKey=<CalExchangeUpdateCalendarItemOperation: 0x7fcf5bb6b800>, NSLocalizedDescription=Calendar can’t save the event “Developer Meeting” to the Exchange server.}]
6/4/13 11:24:25.280 AM CalendarAgent[8764]: [com.apple.calendar.store.log.exchange.queue] [error = Error Domain=CalExchangeErrorDomain Code=-4 "Calendar can’t save the event “Developer Meeting” to the Exchange server." UserInfo=0x7fcf59461010 {NSLocalizedFailureReason=The account "Cshs" currently can’t be modified. To discard your changes and continue using the version of your calendars that’s on the server, click Revert to Server., CalFailedOperationKey=<CalExchangeUpdateCalendarItemOperation: 0x7fcf5bb6b800>, NSLocalizedDescription=Calendar can’t save the event “Developer Meeting” to the Exchange server.}]
6/4/13 11:24:30.288 AM KernelEventAgent[43]: tid 00000000 received event(s) VQ_LOWDISK, VQ_VERYLOWDISK (516)
6/4/13 11:24:30.000 AM kernel[0]: HFS: Vol: Google Chrome 27.0.1453.93-27.0.1453.110 Update Very Low Disk: freeblks: 0, dangerlimit: 13
6/4/13 11:24:30.507 AM DiskMountedNotifier[8779]: Try #0, for     , result = -600
6/4/13 11:24:31.000 AM kernel[0]: CODE SIGNING: cs_invalid_page(0x1000): p=8935[ksadmin] clearing CS_VALID
6/4/13 11:24:32.000 AM kernel[0]: CODE SIGNING: cs_invalid_page(0x1000): p=8938[ksadmin] clearing CS_VALID
6/4/13 11:24:32.000 AM kernel[0]: CODE SIGNING: cs_invalid_page(0x1000): p=8940[ksadmin] clearing CS_VALID
6/4/13 11:24:32.508 AM DiskMountedNotifier[8779]: Try #1, for     , result = 0
6/4/13 11:24:32.508 AM DiskMountedNotifier[8779]: launch for id = 0      event = Mscn result = 0
6/4/13 11:24:33.396 AM com.apple.backupd[8783]: Using file event preflight for Macintosh HD
6/4/13 11:24:33.550 AM defaults[8944]: 
The domain/default pair of (/Applications/Google Chrome.app/Contents/Info, KSBrandID) does not exist
6/4/13 11:24:47.684 AM Mail[9635]: Using V2 Layout
6/4/13 11:24:53.307 AM librariand[9662]: MMe quota status changed: under quota
6/4/13 11:24:55.846 AM com.apple.launchd[1]: System: Bug: 12E27: launchd + 80370 [7DCC9489-2DF5-3807-83FA-EF5666EE8078]: 0x0
6/4/13 11:24:55.846 AM com.apple.launchd[1]: System: This API can only be used by a process running within an Aqua session.
6/4/13 11:24:55.846 AM osascript[9809]: spawn_via_launchd() failed, errno=5 label=[0x0-0x1e61e6].com.apple.systemevents path=/System/Library/CoreServices/System Events.app/Contents/MacOS/System Events flags=0
6/4/13 11:24:55.846 AM osascript[9809]: spawn_via_launchd() failed, errno=5 label=[0x0-0x1e61e6].com.apple.systemevents path=/System/Library/CoreServices/System Events.app/Contents/MacOS/System Events flags=0
6/4/13 11:25:01.744 AM netbiosd[147]: name servers down?
6/4/13 11:25:03.637 AM com.apple.SecurityServer[15]: Session 100013 created
6/4/13 11:25:07.760 AM com.apple.time[8719]: Interval maximum value is 946100000 seconds (specified value: 9223372036854775807).
6/4/13 11:25:12.268 AM LiveUpdate[8791]: Cannot create Symantec.keychain: Permission denied.
6/4/13 11:25:12.275 AM LiveUpdate[8791]: Cannot create Symantec.keychain: Permission denied.
6/4/13 11:25:15.000 AM kernel[0]: AppleBCM5701Ethernet:        0        1 BCM5701Enet::replaceOrCopyPacket worked after N tries

Since I'm limited in how much I can post, I edited out a lot of acvpnagent entries such as this one:

6/4/13 11:20:00.007 AM acvpnagent[62]: Function: if_get_interfaces File: Utility/if_unix.cpp Line: 186 Invoked Function: ioctl Return Code: -1 (0xFFFFFFFF) Description: unknown (SIOCGIFDSTADDR) for interface "utun0"

I think this is related to some stuff work installed on my machine before I got it, but there are lots of these messages prior to attempting to log in, so I think they're unrelated.

UPDATE 1:

I tried the solution proposed here:

http://www.techsmog.com/index.php/2011/02/23/fixing-the-slow-loginlogoutauthentication-issue-in-osx-snow-leopard/

but this did not help.


Solution 1:

Okay, found the solution. Not sure which of these did the trick as I did both at once:

1) Shut down computer, unplug power cord and wait 15 seconds. Plug cord back in and wait 5 seconds, then turn on.

2) Immediately after turning on (before gray screen appears but after chime) hold down Command-Option-P-R all at once to zap PRAM. Keep holding until computer restart.

Now shutting down takes only 30 seconds, and logging in takes only 15. Soooooo much better!