| ## Annotated console output showing a mid-2011 iMac losing wifi connection after waking from sleep. | |
| ## Here the iMac wakes from sleep: | |
| 2014-10-01 8:16:32.000 PM kernel[0]: Wake reason: EHC2 | |
| 2014-10-01 8:16:32.000 PM kernel[0]: Previous Sleep Cause: 5 | |
| 2014-10-01 8:16:32.000 PM kernel[0]: The USB device HubDevice (Port 1 of Hub at 0xfa000000) may have caused a wake by issuing a remote wakeup (2) | |
| 2014-10-01 8:16:32.000 PM kernel[0]: AppleThunderboltHAL::earlyWake - complete - took 1 milliseconds | |
| 2014-10-01 8:16:32.000 PM kernel[0]: 226511.782954: ar9300WowWakeUp: Skip PCIE WA programming | |
| 2014-10-01 8:16:32.000 PM kernel[0]: 226511.782975: setDISASSOC from ATH_INTERFACE_CLASS disconnectVap | |
| 2014-10-01 8:16:32.000 PM kernel[0]: AirPort: Link Down on en1. Reason 8 (Disassociated because station leaving). | |
| 2014-10-01 8:16:32.000 PM kernel[0]: 226511.802749: setDISASSOCIATE ****STA SYNC DISASSOC SUCCESS | |
| 2014-10-01 8:16:32.030 PM UserEventAgent[11]: Captive: CNPluginHandler en1: Inactive | |
| 2014-10-01 8:16:32.000 PM kernel[0]: The USB device BRCM2046 Hub (Port 1 of Hub at 0xfa100000) may have caused a wake by issuing a remote wakeup (3) | |
| 2014-10-01 8:16:32.000 PM kernel[0]: The USB device Bluetooth USB Host Controller (Port 1 of Hub at 0xfa110000) may have caused a wake by issuing a remote wakeup (3) | |
| 2014-10-01 8:16:32.000 PM kernel[0]: Thunderbolt Self-Reset Count = 0xedefbe00 | |
| 2014-10-01 8:16:32.000 PM kernel[0]: TBT W (1): 0 [x] | |
| 2014-10-01 8:16:32.000 PM kernel[0]: **** [IOBluetoothHostControllerUSBTransport][SuspendDevice] -- Resume -- suspendDeviceCallResult = 0x0000 (kIOReturnSuccess) -- 0x7000 **** | |
| 2014-10-01 8:16:32.000 PM kernel[0]: 226511.954214: performCountryCodeOperation: Not connected, scan in progress[0] | |
| 2014-10-01 8:16:32.000 PM kernel[0]: full wake (reason 1) 178 ms | |
| 2014-10-01 8:16:32.000 PM kernel[0]: **** [IOBluetoothHCIController][ProcessEventDataWL] -- calling mDisplayManager->activityTickle() to wake up the display | |
| 2014-10-01 8:16:32.285 PM WindowServer[90]: CGXDisplayDidWakeNotification [226512061941920]: posting kCGSDisplayDidWake | |
| 2014-10-01 8:16:32.286 PM WindowServer[90]: handle_will_sleep_auth_and_shield_windows: NULL shield_window (lock state: 1) | |
| 2014-10-01 8:16:33.637 PM hidd[46]: MultitouchHID: device bootloaded | |
| ## NOTE: it remembers its IP address (192.168.1.32) here: | |
| 2014-10-01 8:16:39.210 PM netbiosd[13930]: network_reachability_changed : network is not reachable, netbiosd is shutting down | |
| 2014-10-01 8:16:39.452 PM configd[17]: network changed: v4(en1-:192.168.1.32) DNS- Proxy- | |
| 2014-10-01 8:16:40.000 PM kernel[0]: en1: 802.11d country code set to 'US '. | |
| 2014-10-01 8:16:40.000 PM kernel[0]: en1: Supported channels 1 2 3 4 5 6 7 8 9 10 11 36 40 44 48 52 56 60 64 100 104 108 112 116 120 124 128 132 136 140 149 153 157 161 165 | |
| 2014-10-01 8:16:41.000 PM kernel[0]: en1: BSSID changed to 00:xx:9c:34:yy:zz | |
| 2014-10-01 8:16:41.000 PM kernel[0]: AirPort: Link Up on en1 | |
| ## ... but we have no network access: | |
| 2014-10-01 8:16:41.000 PM kernel[0]: 226521.105289: apple80211Request[10514] Unsupported ioctl 181 | |
| 2014-10-01 8:16:41.000 PM kernel[0]: en1: BSSID changed to 00:xx:9c:34:yy:zz | |
| 2014-10-01 8:16:41.000 PM kernel[0]: AirPort: RSN handshake complete on en1 | |
| 2014-10-01 8:16:41.000 PM kernel[0]: flow_divert_kctl_disconnect (0): disconnecting group 1 | |
| 2014-10-01 8:16:51.996 PM AirPlayUIAgent[13467]: 2014-10-01 08:16:51.996155 PM [AirPlayUIAgent] Changed PIN pairing: no | |
| 2014-10-01 8:16:52.042 PM AirPlayUIAgent[13467]: 2014-10-01 08:16:52.042014 PM [AirPlayUIAgent] Changed PIN pairing: no | |
| 2014-10-01 8:17:06.214 PM configd[17]: subnet_route: write routing socket failed, Network is unreachable | |
| 2014-10-01 8:17:08.181 PM configd[17]: network changed: Proxy | |
| 2014-10-01 8:17:13.278 PM CalendarAgent[177]: [com.apple.calendar.store.log.subscription] [Failed to refresh <CalManagedSubscriptionInfo: 0x7f9ef846e560> (entity: SubscriptionInfo; id: 0x4000ab <x-coredata://5524C675-B80E-4AC6-A522-BBD3DB920585/SubscriptionInfo/p1> ; data: { | |
| calendar = "0xc0006b <x-coredata://5524C675-B80E-4AC6-A522-BBD3DB920585/SubscriptionCalendar/p3>"; | |
| hasAlarmFilter = 1; | |
| hasAttachmentFilter = 1; | |
| hasTaskFilter = 1; | |
| isAutoProvisioned = 1; | |
| isAutoRefreshed = 1; | |
| languageCode = en; | |
| lastError = "0x4f0000cb <x-coredata://5524C675-B80E-4AC6-A522-BBD3DB920585/SubscriptionError/p316>"; | |
| locationCode = CA; | |
| needsRefresh = 0; | |
| refreshDate = "2014-10-01 23:19:15 +0000"; | |
| refreshInterval = 604800; | |
| subscriptionID = nil; | |
| subscriptionNotes = nil; | |
| subscriptionTitle = "Canadian Holidays"; | |
| subscriptionURL = "(...not nil..)"; | |
| subscriptionURLString = "https://p17-calendars.icloud.com/holiday/CA_en.ics"; | |
| }) with error Error Domain=NSURLErrorDomain Code=-1009 "The Internet connection appears to be offline." UserInfo=0x7f9ef8475550 {NSUnderlyingError=0x7f9efad2fdd0 "The Internet connection appears to be offline.", NSErrorFailingURLStringKey=https://p17-calendars.icloud.com/holiday/CA_en.ics, NSErrorFailingURLKey=https://p17-calendars.icloud.com/holiday/CA_en.ics, NSLocalizedDescription=The Internet connection appears to be offline.}] | |
| 2014-10-01 8:17:14.005 PM com.apple.backupd[13956]: Starting automatic backup | |
| 2014-10-01 8:17:14.232 PM com.apple.backupd[13956]: Attempting to mount network destination URL: afp://time-machine@backupserver.local/TimeMachine | |
| 2014-10-01 8:17:20.274 PM NetAuthSysAgent[13957]: ERROR: AFP_GetServerInfo - connect failed 64 | |
| 2014-10-01 8:17:20.297 PM com.apple.backupd[13956]: NAConnectToServerSync failed with error: 64 for url: afp://time-machine@fenixfunk5.local/TimeMachine | |
| 2014-10-01 8:17:20.402 PM com.apple.backupd[13956]: Backup failed with error 18: The backup disk could not be found. | |
| 2014-10-01 8:18:21.311 PM WindowServer[90]: disable_update_timeout: UI updates were forcibly disabled by application "Terminal" for over 1.00 seconds. Server has re-enabled them. | |
| 2014-10-01 8:18:21.330 PM WindowServer[90]: common_reenable_update: UI updates were finally reenabled by application "Terminal" after 1.02 seconds (server forcibly re-enabled them after 1.00 seconds) | |
| 2014-10-01 8:18:29.409 PM login[13965]: USER_PROCESS: 13965 ttys000 | |
| 2014-10-01 8:18:29.738 PM findNames[13966]: dispatch_semaphore_wait() time out: -[IMKUserDictionary reloadWithCompletionHandler:] | |
| 2014-10-01 8:19:56.587 PM com.apple.IconServicesAgent[13788]: main Failed to composit image for binding VariantBinding [0x2c5] flags: 0x8 binding: FileInfoBinding [0x1d1] - extension: txt, UTI: public.plain-text, fileType: ????. | |
| 2014-10-01 8:19:56.596 PM quicklookd[13983]: Warning: Cache image returned by the server has size range covering all valid image sizes. Binding: VariantBinding [0x203] flags: 0x8 binding: FileInfoBinding [0x103] - extension: txt, UTI: public.plain-text, fileType: ???? request size:64 scale: 1 | |
| 2014-10-01 8:21:19.133 PM WindowServer[90]: disable_update_timeout: UI updates were forcibly disabled by application "System Preferences" for over 1.00 seconds. Server has re-enabled them. | |
| 2014-10-01 8:21:21.389 PM com.apple.preference.network.remoteservice[14003]: assertion failed: 13F34: liblaunch.dylib + 25164 [A40A0C7B-3216-39B4-8AE0-B5D3BAF1DA8A]: 0x25 | |
| 2014-10-01 8:21:21.421 PM com.apple.preference.network.remoteservice[14003]: assertion failed: 13F34: liblaunch.dylib + 25164 [A40A0C7B-3216-39B4-8AE0-B5D3BAF1DA8A]: 0x25 | |
| 2014-10-01 8:21:23.612 PM com.apple.preference.network.remoteservice[14003]: Bogus event received by listener connection: | |
| <error: 0x7fff7a9fbb50> { count = 1, contents = | |
| "XPCErrorDescription" => <string: 0x7fff7a9fbe60> { length = 18, contents = "Connection invalid" } | |
| } | |
| 2014-10-01 8:21:25.433 PM WindowServer[90]: common_reenable_update: UI updates were finally reenabled by application "System Preferences" after 7.30 seconds (server forcibly re-enabled them after 1.00 seconds) | |
| 2014-10-01 8:21:26.687 PM com.apple.preference.network.remoteservice[14003]: *** WARNING: -[NSImage compositeToPoint:operation:fraction:] is deprecated in MacOSX 10.8 and later. Please use -[NSImage drawAtPoint:fromRect:operation:fraction:] instead. | |
| 2014-10-01 8:21:26.688 PM com.apple.preference.network.remoteservice[14003]: *** WARNING: -[NSImage compositeToPoint:fromRect:operation:fraction:] is deprecated in MacOSX 10.8 and later. Please use -[NSImage drawAtPoint:fromRect:operation:fraction:] instead. | |
| 2014-10-01 8:21:39.275 PM WindowServer[90]: window 1642 is already attached to window 163c | |
| 2014-10-01 8:21:40.312 PM com.apple.preference.network.remoteservice[14003]: Could not find image named 'InvalidDataIcon'. | |
| 2014-10-01 8:21:54.964 PM WindowServer[90]: _CGXGetWindowOrderingGroup: Operation on a window 0x1642 requiring rights 0x5 by caller System Preferences | |
| 2014-10-01 8:21:55.000 PM kernel[0]: SIOCPROTODETACH_IN6: fw0 error=6 | |
| 2014-10-01 8:21:55.000 PM kernel[0]: flow_divert_kctl_disconnect (0): disconnecting group 1 | |
| 2014-10-01 8:21:55.656 PM configd[17]: network changed: Proxy | |
| 2014-10-01 8:21:58.265 PM WindowServer[90]: window 1642 is already attached to window 163c | |
| 2014-10-01 8:22:01.623 PM com.apple.launchd[1]: (com.adobe.fpsaud[14006]) Exited with code: 210 | |
| 2014-10-01 8:22:09.145 PM WindowServer[90]: _CGXGetWindowOrderingGroup: Operation on a window 0x1642 requiring rights 0x5 by caller System Preferences | |
| 2014-10-01 8:22:09.000 PM kernel[0]: SIOCPROTODETACH_IN6: fw0 error=6 | |
| 2014-10-01 8:22:09.000 PM kernel[0]: flow_divert_kctl_disconnect (0): disconnecting group 1 | |
| 2014-10-01 8:22:16.051 PM WindowServer[90]: window 1642 is already attached to window 163c | |
| 2014-10-01 8:22:24.452 PM WindowServer[90]: _CGXGetWindowOrderingGroup: Operation on a window 0x1642 requiring rights 0x5 by caller System Preferences | |
| 2014-10-01 8:22:26.219 PM configd[17]: subnet_route: write routing socket failed, Network is unreachable | |
| 2014-10-01 8:22:28.092 PM configd[17]: network changed: Proxy | |
| 2014-10-01 8:22:32.101 PM CalendarAgent[177]: [com.apple.calendar.store.log.subscription] [Failed to refresh <CalManagedSubscriptionInfo: 0x7f9ef87efde0> (entity: SubscriptionInfo; id: 0x4000ab <x-coredata://5524C675-B80E-4AC6-A522-BBD3DB920585/SubscriptionInfo/p1> ; data: { | |
| calendar = "0xc0006b <x-coredata://5524C675-B80E-4AC6-A522-BBD3DB920585/SubscriptionCalendar/p3>"; | |
| hasAlarmFilter = 1; | |
| hasAttachmentFilter = 1; | |
| hasTaskFilter = 1; | |
| isAutoProvisioned = 1; | |
| isAutoRefreshed = 1; | |
| languageCode = en; | |
| lastError = "0x4f8000cb <x-coredata://5524C675-B80E-4AC6-A522-BBD3DB920585/SubscriptionError/p318>"; | |
| locationCode = CA; | |
| needsRefresh = 0; | |
| refreshDate = "2014-10-01 23:19:15 +0000"; | |
| refreshInterval = 604800; | |
| subscriptionID = nil; | |
| subscriptionNotes = nil; | |
| subscriptionTitle = "Canadian Holidays"; | |
| subscriptionURL = "(...not nil..)"; | |
| subscriptionURLString = "https://p17-calendars.icloud.com/holiday/CA_en.ics"; | |
| }) with error Error Domain=NSURLErrorDomain Code=-1009 "The Internet connection appears to be offline." UserInfo=0x7f9ef87f8dc0 {NSUnderlyingError=0x7f9efaf0a810 "The Internet connection appears to be offline.", NSErrorFailingURLStringKey=https://p17-calendars.icloud.com/holiday/CA_en.ics, NSErrorFailingURLKey=https://p17-calendars.icloud.com/holiday/CA_en.ics, NSLocalizedDescription=The Internet connection appears to be offline.}] | |
| 2014-10-01 8:22:41.098 PM com.apple.preference.network.remoteservice[14003]: remote view marshal proxy failed to forward event to remote due to Error Domain=NSCocoaErrorDomain Code=4099 "Couldn’t communicate with a helper application." (The connection was invalidated from the other process or the connection name was invalid.) UserInfo=0x7f90225a0b70 {NSDebugDescription=The connection was invalidated from the other process or the connection name was invalid.} | |
| timestamp: 20:22:41.097 Wednesday 01 October 2014 | |
| process/thread/queue: com.apple.preference.network.remoteservice (14003) / 0x10d97e000 / com.apple.NSXPCConnection.user.13996 | |
| code: line 1006 of /SourceCache/ViewBridge/ViewBridge-46.2/NSViewServiceMarshal.m in __59-[NSViewServiceMarshal remoteViewMarshal:withErrorHandler:]_block_invoke | |
| domain: communications-failure | |
| ## At this point, I open Terminal and manually reset en1 from the command line: | |
| 2014-10-01 8:22:44.358 PM launchservicesd[54]: Application App:"Terminal" asn:0x0-69069 pid:8048 refs=7 @ 0x7ff2e9537210 tried to be brought forward, but isn't in fPermittedFrontApps ( ( "LSApplication:0x0-0x10f10f pid=14010 "SecurityAgent"")), so denying. : LASSession.cp #1481 SetFrontApplication() q=LSSession 100004/0x186a4 queue | |
| 2014-10-01 8:22:44.358 PM WindowServer[90]: [cps/setfront] Failed setting the front application to Terminal, psn 0x0-0x69069, securitySessionID=0x186a4, err=-13066 | |
| 2014-10-01 8:22:44.476 PM authexec[14012]: executing /System/Library/ScriptingAdditions/StandardAdditions.osax/Contents/MacOS/uid | |
| 2014-10-01 8:22:44.692 PM sudo[14013]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig en1 down | |
| 2014-10-01 8:22:44.000 PM kernel[0]: AirPort: Link Down on en1. Reason 8 (Disassociated because station leaving). | |
| 2014-10-01 8:22:44.000 PM kernel[0]: en1: BSSID changed to 00:xx:9c:34:yy:zz | |
| 2014-10-01 8:22:44.000 PM kernel[0]: 226884.508642: setDISASSOC from ATH_INTERFACE_CLASS disconnectVap | |
| 2014-10-01 8:22:46.000 PM kernel[0]: 226886.635097: setDISASSOCIATE ****STA SYNC DISASSOC SUCCESS | |
| 2014-10-01 8:22:46.000 PM kernel[0]: 226886.635107: switchVap from 1 to 1 | |
| 2014-10-01 8:22:46.000 PM kernel[0]: process ifconfig[14014] caught causing excessive wakeups. Observed wakeups rate (per sec): 30787; Maximum permitted wakeups rate (per sec): 150; Observation period: 300 seconds; Task lifetime number of wakeups: 66932 | |
| 2014-10-01 8:22:46.867 PM airportd[64]: _handleLinkEvent: WiFi is not powered. Resetting state variables. | |
| 2014-10-01 8:22:47.112 PM sudo[14017]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig en1 up | |
| ## Here en1 is coming up... | |
| 2014-10-01 8:22:47.872 PM configd[17]: network changed: Proxy | |
| 2014-10-01 8:22:48.000 PM kernel[0]: en1: BSSID changed to 00:xx:9c:34:yy:zz | |
| 2014-10-01 8:22:48.000 PM kernel[0]: AirPort: Link Up on en1 | |
| 2014-10-01 8:22:48.000 PM kernel[0]: 226888.562413: apple80211Request[10514] Unsupported ioctl 181 | |
| 2014-10-01 8:22:48.000 PM kernel[0]: en1: BSSID changed to 00:xx:9c:34:yy:zz | |
| 2014-10-01 8:22:48.000 PM kernel[0]: AirPort: RSN handshake complete on en1 | |
| 2014-10-01 8:22:49.000 PM kernel[0]: flow_divert_kctl_disconnect (0): disconnecting group 1 | |
| 2014-10-01 8:22:53.672 PM configd[17]: network changed: DNS* Proxy | |
| 2014-10-01 8:22:53.693 PM UserEventAgent[11]: Captive: [CNInfoNetworkActive:1655] en1: SSID 'MyWifi' making interface primary (cache indicates network not captive) | |
| 2014-10-01 8:22:53.694 PM UserEventAgent[11]: Captive: CNPluginHandler en1: Evaluating | |
| # And now the network connection works again: | |
| 2014-10-01 8:22:53.786 PM configd[17]: network changed: v4(en1!:192.168.1.32) DNS+ Proxy+ SMB | |
| 2014-10-01 8:22:53.805 PM UserEventAgent[11]: Captive: en1: Not probing 'MyWifi' (cache indicates not captive) | |
| 2014-10-01 8:22:53.807 PM UserEventAgent[11]: Captive: CNPluginHandler en1: Authenticated | |
| 2014-10-01 8:22:55.408 PM apsd[62]: Unrecognized leaf certificate | |
| 2014-10-01 8:23:01.129 PM AirPlayUIAgent[13467]: 2014-10-01 08:23:01.128527 PM [AirPlayUIAgent] Changed PIN pairing: no | |
| 2014-10-01 8:23:01.267 PM AirPlayUIAgent[13467]: 2014-10-01 08:23:01.266967 PM [AirPlayUIAgent] Changed PIN pairing: no | |
| 2014-10-01 8:23:03.155 PM login[13965]: DEAD_PROCESS: 13965 ttys000 | |
| 2014-10-01 8:26:05.799 PM Console[14030]: setPresentationOptions called with NSApplicationPresentationFullScreen when there is no visible fullscreen window; this call will be ignored. | |
| 2014-10-01 8:26:12.268 PM WindowServer[90]: disable_update_timeout: UI updates were forcibly disabled by application "Console" for over 1.00 seconds. Server has re-enabled them. | |
| 2014-10-01 8:26:13.294 PM com.apple.IconServicesAgent[13788]: main Failed to composit image for binding VariantBinding [0x2cd] flags: 0x8 binding: FileInfoBinding [0x1d7] - extension: gif, UTI: com.compuserve.gif, fileType: ????. | |
| 2014-10-01 8:26:13.294 PM quicklookd[14032]: Warning: Cache image returned by the server has size range covering all valid image sizes. Binding: VariantBinding [0x203] flags: 0x8 binding: FileInfoBinding [0x103] - extension: gif, UTI: com.compuserve.gif, fileType: ???? request size:16 scale: 1 | |
| 2014-10-01 8:26:14.744 PM WindowServer[90]: common_reenable_update: UI updates were finally reenabled by application "Console" after 3.48 seconds (server forcibly re-enabled them after 1.00 seconds) | |
| 2014-10-01 8:26:13.294 PM com.apple.IconServicesAgent[13788]: main Failed to composit image for binding VariantBinding [0x2cd] flags: 0x8 binding: FileInfoBinding [0x1d7] - extension: gif, UTI: com.compuserve.gif, fileType: ????. | |
| 2014-10-01 8:26:13.294 PM quicklookd[14032]: Warning: Cache image returned by the server has size range covering all valid image sizes. Binding: VariantBinding [0x203] flags: 0x8 binding: FileInfoBinding [0x103] - extension: gif, UTI: com.compuserve.gif, fileType: ???? request size:16 scale: 1 | |
| 2014-10-01 8:26:14.744 PM WindowServer[90]: common_reenable_update: UI updates were finally reenabled by application "Console" after 3.48 seconds (server forcibly re-enabled them after 1.00 seconds) | |
| 2014-10-01 8:26:13.294 PM com.apple.IconServicesAgent[13788]: main Failed to composit image for binding VariantBinding [0x2cd] flags: 0x8 binding: FileInfoBinding [0x1d7] - extension: gif, UTI: com.compuserve.gif, fileType: ????. | |
| 2014-10-01 8:26:13.294 PM quicklookd[14032]: Warning: Cache image returned by the server has size range covering all valid image sizes. Binding: VariantBinding [0x203] flags: 0x8 binding: FileInfoBinding [0x103] - extension: gif, UTI: com.compuserve.gif, fileType: ???? request size:16 scale: 1 | |
| 2014-10-01 8:26:14.744 PM WindowServer[90]: common_reenable_update: UI updates were finally reenabled by application "Console" after 3.48 seconds (server forcibly re-enabled them after 1.00 seconds) |
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment