Hi Folks,
My MBP sometimes wakes up from sleep for no apparent reason. I have it set up in a closed lid/external monitor mode, with a bluetooth keyboard and a wireless usb mouse. To make sure it's not USB activity, I unplugged all USB devices, and switched the USB mouse off. Also made sure "wakeup on ethernet access" is disabled in system prefs, and software update is turned off.
Looking at the console, it woke up with a reason:
Wake reason = EHC2 OHC2
Do you know what that is?
Below is a system.log snapshot and console messages when it woke up. Any ideas about what caused it?
Thanks
Mike
System.log:
Console messages:
My MBP sometimes wakes up from sleep for no apparent reason. I have it set up in a closed lid/external monitor mode, with a bluetooth keyboard and a wireless usb mouse. To make sure it's not USB activity, I unplugged all USB devices, and switched the USB mouse off. Also made sure "wakeup on ethernet access" is disabled in system prefs, and software update is turned off.
Looking at the console, it woke up with a reason:
Wake reason = EHC2 OHC2
Do you know what that is?
Below is a system.log snapshot and console messages when it woke up. Any ideas about what caused it?
Thanks
Mike
System.log:
Code:
Dec 10 07:42:30 MishkaMac kernel[0]: /drv/ MacModule.cpp:266 powerStateWillChangeTo: found flag=kIOPMSleepCapability (4)
Dec 10 07:42:30 MishkaMac kernel[0]: AirPort: Link Down on en1
Dec 10 07:42:30 MishkaMac kernel[0]: vmnet: bridge-en1: interface en is going DOWN
Dec 10 07:42:30 MishkaMac kernel[0]: vmmon: powerStateDidChange flags=0x4 (state 2)
Dec 10 07:42:30 MishkaMac kernel[0]: /drv/ MacModule.cpp:261 powerStateDidChangeTo: flags=4 stateNumber=2
Dec 10 07:42:30 MishkaMac kernel[0]: /drv/ MacModule.cpp:266 powerStateDidChangeTo: found flag=kIOPMSleepCapability (4)
Dec 9 23:34:24 MishkaMac kernel[0]: System SafeSleep
Dec 10 07:42:30 MishkaMac kernel[0]: hibernate_page_list_setall start
Dec 10 07:42:30 MishkaMac kernel[0]: hibernate_page_list_setall time: 137 ms
Dec 10 07:42:30 MishkaMac kernel[0]: pages 395703, wire 207938, act 90073, inact 97, zf 0, throt 2117, could discard act 47739 inact 42396 purgeable 5343
Dec 10 07:42:30 MishkaMac kernel[0]: hibernate_page_list_setall found pageCount 300225
Dec 10 07:42:30 MishkaMac kernel[0]: IOHibernatePollerOpen, ml_get_interrupts_enabled 0
Dec 10 07:42:30 MishkaMac kernel[0]: IOHibernatePollerOpen(0)
Dec 10 07:42:30 MishkaMac kernel[0]: writing 298125 pages
Dec 10 07:42:30 MishkaMac kernel[0]: image1Size 554119168
Dec 10 07:42:30 MishkaMac kernel[0]: all time: 10139 ms, comp time: 1825 ms, deco time: 0 ms,
Dec 10 07:42:30 MishkaMac kernel[0]: image 774316032, uncompressed 1221120000 (298125), compressed 767945764 (62%), sum1 9233ab37, sum2 7a4aa7fc
Dec 10 07:42:30 MishkaMac kernel[0]: hibernate_write_image done(0)
Dec 10 07:42:30 MishkaMac kernel[0]: sleep
Dec 10 07:42:30 MishkaMac kernel[0]: Wake reason = EHC2 OHC2
Dec 10 07:42:30 MishkaMac kernel[0]: System Wake
Dec 10 07:42:30 MishkaMac kernel[0]: /drv/ MacModule.cpp:261 powerStateWillChangeTo: flags=82 stateNumber=4
Dec 10 07:42:30 MishkaMac kernel[0]: /drv/ MacModule.cpp:262 powerStateWillChangeTo: found flag=kIOPMPowerOn (2)
Dec 10 07:42:30 MishkaMac kernel[0]: /drv/ MacModule.cpp:267 powerStateWillChangeTo: found flag=kIOPMRestartCapability (80)
Dec 10 07:42:30 MishkaMac kernel[0]: vmmon: powerStateDidChange flags=0x82 (state 4)
Dec 10 07:42:30 MishkaMac kernel[0]: /drv/ MacModule.cpp:261 powerStateDidChangeTo: flags=82 stateNumber=4
Dec 10 07:42:30 MishkaMac kernel[0]: /drv/ MacModule.cpp:262 powerStateDidChangeTo: found flag=kIOPMPowerOn (2)
Dec 10 07:42:30 MishkaMac kernel[0]: /drv/ MacModule.cpp:267 powerStateDidChangeTo: found flag=kIOPMRestartCapability (80)
Dec 10 07:42:30 MishkaMac kernel[0]: Previous Sleep Cause: 5
Dec 10 07:42:30 MishkaMac kernel[0]: USB (EHCI):Port 1 on bus 0x26 connected or disconnected: portSC(0x101803)
Dec 10 07:42:30 MishkaMac kernel[0]: USB (OHCI):Port 1 on bus 0x6 connected or disconnected. portSC(0x30100)
Dec 10 07:42:30 MishkaMac kernel[0]: en1: 802.11d country code set to 'X0'.
Dec 10 07:42:30 MishkaMac kernel[0]: en1: Supported channels 1 2 3 4 5 6 7 8 9 10 11 5 6 7 8 9 10 11 1 2 3 4 5 6 7 36 40 44 48 52 56 60 64 100 104 108 112 116 120 124 128 132 136 140 149 153 157 161 165 40 48 56 64 104 112 120 128 136 153 161 36 44 52 60
Dec 10 07:42:30 MishkaMac kernel[0]: [InterruptReadHandler] Received kIODeviceNotResponding error - retrying: 1.
Dec 10 07:42:30 MishkaMac kernel[0]: EIR is supported.
Dec 10 07:42:30 MishkaMac kernel[0]: SSP is supported.
Dec 10 07:42:30 MishkaMac kernel[0]: Link Down
Dec 10 07:42:31 MishkaMac kernel[0]: vmnet: VMNetDisconnect called for port 0x7d5e600
Dec 10 07:42:31 MishkaMac kernel[0]: vmnet: bridge-en1: filter detached
Dec 10 07:42:31 MishkaMac kernel[0]: vmnet: bridge-en1: down
Dec 10 07:42:31 MishkaMac kernel[0]: vmnet: bridge-en1: detached
Dec 10 07:42:31 MishkaMac kernel[0]: vmnet: Freeing hub at 0x78cc000.
Dec 10 07:42:31 MishkaMac kernel[0]: vmnet: VNetUserIf_Create: created userIf at 0x7d5e600.
Dec 10 07:42:31 MishkaMac kernel[0]: vmnet: VMNetConnect: returning port 0x7d5e600
Dec 10 07:42:31 MishkaMac kernel[0]: vmnet: Hub 0 does not exist, allocating memory.
Dec 10 07:42:31 MishkaMac kernel[0]: vmnet: Allocated hub 0x78cc000 for hubNum 0.
Dec 10 07:42:31 MishkaMac kernel[0]: vmnet: VMNET_SO_BINDTOHUB: port: paddr 00:50:56:f7:04:e6
Dec 10 07:42:31 MishkaMac kernel[0]: vmnet: Hub 0
Dec 10 07:42:31 MishkaMac kernel[0]: vmnet: Port 0
Dec 10 07:42:31 MishkaMac kernel[0]: vmnet: bridge-en2: got dev 0x7644404
Dec 10 07:42:31 MishkaMac kernel[0]: vmnet: bridge-en2: up
Dec 10 07:42:31 MishkaMac kernel[0]: vmnet: bridge-en2: attached
Dec 10 07:42:31 MishkaMac kernel[0]: vmnet: VNetUserIfFree: freeing userIf at 0x7d5e600.
Dec 10 07:42:34 MishkaMac kernel[0]: MAC AUTH succeeded
Dec 10 07:42:34 MishkaMac kernel[0]: AirPort: Link Up on en1
Dec 10 07:42:34 MishkaMac kernel[0]: vmnet: VMNetDisconnect called for port 0x7bffd00
Dec 10 07:42:34 MishkaMac kernel[0]: vmnet: bridge-en2: filter detached
Dec 10 07:42:34 MishkaMac kernel[0]: vmnet: bridge-en2: down
Dec 10 07:42:34 MishkaMac kernel[0]: vmnet: bridge-en2: detached
Dec 10 07:42:34 MishkaMac kernel[0]: vmnet: Freeing hub at 0x78cc000.
Dec 10 07:42:34 MishkaMac kernel[0]: vmnet: VNetUserIf_Create: created userIf at 0x7bffd00.
Dec 10 07:42:34 MishkaMac kernel[0]: vmnet: VMNetConnect: returning port 0x7bffd00
Dec 10 07:42:34 MishkaMac kernel[0]: vmnet: Hub 0 does not exist, allocating memory.
Dec 10 07:42:34 MishkaMac kernel[0]: vmnet: Allocated hub 0x78cc000 for hubNum 0.
Dec 10 07:42:34 MishkaMac kernel[0]: vmnet: VMNET_SO_BINDTOHUB: port: paddr 00:50:56:f8:bc:98
Dec 10 07:42:34 MishkaMac kernel[0]: vmnet: Hub 0
Dec 10 07:42:34 MishkaMac kernel[0]: vmnet: Port 0
Dec 10 07:42:34 MishkaMac kernel[0]: vmnet: bridge-en1: got dev 0x7810a04
Dec 10 07:42:34 MishkaMac kernel[0]: vmnet: bridge-en1: wireless interface detected.
Dec 10 07:42:34 MishkaMac kernel[0]: vmnet: bridge-en1: up
Dec 10 07:42:34 MishkaMac kernel[0]: vmnet: bridge-en1: attached
Dec 10 07:42:34 MishkaMac kernel[0]: vmnet: VNetUserIfFree: freeing userIf at 0x7bffd00.
Dec 10 07:42:37 MishkaMac kernel[0]: [[0x850a000] Req OpCode 0c3f from: kernel_task (0) status: 0 state: 2 timeout: 10000] Bluetooth warning: An HCI Req timeout occurred.
Dec 10 07:42:37 MishkaMac kernel[0]: E:[AppleUSBBluetoothHCIController]WARNING !!!! [DeviceRequestCompleteHandler] error e00002ed
Dec 10 07:42:42 MishkaMac kernel[0]: [[0x8530000] Req OpCode 0c01 from: kernel_task (0) status: 0 state: 2 timeout: 5000] Bluetooth warning: An HCI Req timeout occurred.
Dec 10 07:42:42 MishkaMac kernel[0]: E:[AppleUSBBluetoothHCIController]WARNING !!!! [DeviceRequestCompleteHandler] error e00002ed
Dec 10 07:42:42 MishkaMac kernel[0]: E:[AppleUSBBluetoothHCIController][BulkOutWriteCompleteHandler] ERROR1: 0xe00002ed; sizeRem=00000009; isInactive = 0, suspended = 0
Dec 10 07:42:42 MishkaMac kernel[0]: E:[AppleUSBBluetoothHCIController][BulkInReadHandler] Received kIOReturnNotResponding error - retrying: 1.
Dec 10 07:42:42 MishkaMac kernel[0]: E:[AppleUSBBluetoothHCIController][BulkInReadHandler] immediate error (-536854449) queueing next read.
Dec 10 07:42:42 MishkaMac kernel[0]: IOBluetoothHCIController::terminateWL .. done
Dec 10 07:42:43 MishkaMac kernel[0]: [HCIController][configurePM] power parent ready after 1 tries
Dec 10 07:42:43 MishkaMac com.apple.UserEventAgent-Aqua[222]: <CFArray 0x516760 [0xa02641a0]>{type = mutable-small, count = 4, values = (
Dec 10 07:42:43 MishkaMac com.apple.UserEventAgent-Aqua[222]: 0 : <CFString 0x1
Dec 10 07:42:43 MishkaMac com.apple.UserEventAgent-Aqua[222]: 6b8c0 [0xa02641a0]>{contents = "/System/Library/CoreServices/Menu Extras/TextInput.menu"}
Dec 10 07:42:43 MishkaMac com.apple.UserEventAgent-Aqua[222]: 1 : <CFString 0x516680 [0xa02641a0]>{contents = "/System/Library/CoreServices/Menu Extras/Clock.menu"}
Dec 10 07:42:43 MishkaMac com.apple.UserEventAgent-Aqua[222]: 2 : <CFString 0x5166c0 [0xa02641a0]>{contents = "/System/Library/CoreServices/Menu Extras/TimeMachine.menu"}
Dec 10 07:42:43 MishkaMac com.apple.UserEventAgent-Aqua[222]: 3 : <CFString 0x516710 [0xa02641a0]>{contents = "/System/Library/CoreServices/Menu Extras/Bluetooth.menu"}
Dec 10 07:42:43 MishkaMac com.apple.UserEventAgent-Aqua[222]: )}
Dec 10 07:55:29 MishkaMac ntpd[14]: time reset +0.551550 s
Console messages:
Code:
12/10/08 Dec 10 7:42:30 AM kernel /drv/ MacModule.cpp:266 powerStateWillChangeTo: found flag=kIOPMSleepCapability (4)
12/10/08 Dec 10 7:42:30 AM kernel AirPort: Link Down on en1
12/10/08 Dec 10 7:42:30 AM kernel vmnet: bridge-en1: interface en is going DOWN
12/10/08 Dec 10 7:42:30 AM kernel vmmon: powerStateDidChange flags=0x4 (state 2)
12/10/08 Dec 10 7:42:30 AM kernel /drv/ MacModule.cpp:261 powerStateDidChangeTo: flags=4 stateNumber=2
12/10/08 Dec 10 7:42:30 AM kernel /drv/ MacModule.cpp:266 powerStateDidChangeTo: found flag=kIOPMSleepCapability (4)
12/9/08 Dec 9 11:34:24 PM kernel System SafeSleep
12/10/08 Dec 10 7:42:30 AM kernel hibernate_page_list_setall start
12/10/08 Dec 10 7:42:30 AM kernel hibernate_page_list_setall time: 137 ms
12/10/08 Dec 10 7:42:30 AM kernel pages 395703, wire 207938, act 90073, inact 97, zf 0, throt 2117, could discard act 47739 inact 42396 purgeable 5343
12/10/08 Dec 10 7:42:30 AM kernel hibernate_page_list_setall found pageCount 300225
12/10/08 Dec 10 7:42:30 AM kernel IOHibernatePollerOpen, ml_get_interrupts_enabled 0
12/10/08 Dec 10 7:42:30 AM kernel IOHibernatePollerOpen(0)
12/10/08 Dec 10 7:42:30 AM kernel writing 298125 pages
12/10/08 Dec 10 7:42:30 AM kernel image1Size 554119168
12/10/08 Dec 10 7:42:30 AM kernel all time: 10139 ms, comp time: 1825 ms, deco time: 0 ms,
12/10/08 Dec 10 7:42:30 AM kernel image 774316032, uncompressed 1221120000 (298125), compressed 767945764 (62%), sum1 9233ab37, sum2 7a4aa7fc
12/10/08 Dec 10 7:42:30 AM kernel hibernate_write_image done(0)
12/10/08 Dec 10 7:42:30 AM kernel sleep
12/10/08 Dec 10 7:42:30 AM kernel Wake reason = EHC2 OHC2
12/10/08 Dec 10 7:42:30 AM kernel System Wake
12/10/08 Dec 10 7:42:30 AM kernel /drv/ MacModule.cpp:261 powerStateWillChangeTo: flags=82 stateNumber=4
12/10/08 Dec 10 7:42:30 AM kernel /drv/ MacModule.cpp:262 powerStateWillChangeTo: found flag=kIOPMPowerOn (2)
12/10/08 Dec 10 7:42:30 AM kernel /drv/ MacModule.cpp:267 powerStateWillChangeTo: found flag=kIOPMRestartCapability (80)
12/10/08 Dec 10 7:42:30 AM kernel vmmon: powerStateDidChange flags=0x82 (state 4)
12/10/08 Dec 10 7:42:30 AM kernel /drv/ MacModule.cpp:261 powerStateDidChangeTo: flags=82 stateNumber=4
12/10/08 Dec 10 7:42:30 AM kernel /drv/ MacModule.cpp:262 powerStateDidChangeTo: found flag=kIOPMPowerOn (2)
12/10/08 Dec 10 7:42:30 AM kernel /drv/ MacModule.cpp:267 powerStateDidChangeTo: found flag=kIOPMRestartCapability (80)
12/10/08 Dec 10 7:42:30 AM kernel Previous Sleep Cause: 5
12/10/08 Dec 10 7:42:30 AM kernel USB (EHCI):Port 1 on bus 0x26 connected or disconnected: portSC(0x101803)
12/10/08 Dec 10 7:42:30 AM kernel USB (OHCI):Port 1 on bus 0x6 connected or disconnected. portSC(0x30100)
12/10/08 Dec 10 7:42:30 AM kernel en1: 802.11d country code set to 'X0'.
12/10/08 Dec 10 7:42:30 AM kernel en1: Supported channels 1 2 3 4 5 6 7 8 9 10 11 5 6 7 8 9 10 11 1 2 3 4 5 6 7 36 40 44 48 52 56 60 64 100 104 108 112 116 120 124 128 132 136 140 149 153 157 161 165 40 48 56 64 104 112 120 128 136 153 161 36 44 52 60
12/10/08 Dec 10 7:42:30 AM kernel [InterruptReadHandler] Received kIODeviceNotResponding error - retrying: 1.
12/10/08 Dec 10 7:42:30 AM kernel EIR is supported.
12/10/08 Dec 10 7:42:30 AM kernel SSP is supported.
12/10/08 Dec 10 7:42:30 AM kernel Link Down
12/10/08 Dec 10 7:42:31 AM kernel vmnet: VMNetDisconnect called for port 0x7d5e600
12/10/08 Dec 10 7:42:31 AM kernel vmnet: bridge-en1: filter detached
12/10/08 Dec 10 7:42:31 AM kernel vmnet: bridge-en1: down
12/10/08 Dec 10 7:42:31 AM kernel vmnet: bridge-en1: detached
12/10/08 Dec 10 7:42:31 AM kernel vmnet: Freeing hub at 0x78cc000.
12/10/08 Dec 10 7:42:31 AM kernel vmnet: VNetUserIf_Create: created userIf at 0x7d5e600.
12/10/08 Dec 10 7:42:31 AM kernel vmnet: VMNetConnect: returning port 0x7d5e600
12/10/08 Dec 10 7:42:31 AM kernel vmnet: Hub 0 does not exist, allocating memory.
12/10/08 Dec 10 7:42:31 AM kernel vmnet: Allocated hub 0x78cc000 for hubNum 0.
12/10/08 Dec 10 7:42:31 AM kernel vmnet: VMNET_SO_BINDTOHUB: port: paddr 00:50:56:f7:04:e6
12/10/08 Dec 10 7:42:31 AM kernel vmnet: Hub 0
12/10/08 Dec 10 7:42:31 AM kernel vmnet: Port 0
12/10/08 Dec 10 7:42:31 AM kernel vmnet: bridge-en2: got dev 0x7644404
12/10/08 Dec 10 7:42:31 AM kernel vmnet: bridge-en2: up
12/10/08 Dec 10 7:42:31 AM kernel vmnet: bridge-en2: attached
12/10/08 Dec 10 7:42:31 AM kernel vmnet: VNetUserIfFree: freeing userIf at 0x7d5e600.
12/10/08 Dec 10 7:42:34 AM kernel MAC AUTH succeeded
12/10/08 Dec 10 7:42:34 AM kernel AirPort: Link Up on en1
12/10/08 Dec 10 7:42:34 AM kernel vmnet: VMNetDisconnect called for port 0x7bffd00
12/10/08 Dec 10 7:42:34 AM kernel vmnet: bridge-en2: filter detached
12/10/08 Dec 10 7:42:34 AM kernel vmnet: bridge-en2: down
12/10/08 Dec 10 7:42:34 AM kernel vmnet: bridge-en2: detached
12/10/08 Dec 10 7:42:34 AM kernel vmnet: Freeing hub at 0x78cc000.
12/10/08 Dec 10 7:42:34 AM kernel vmnet: VNetUserIf_Create: created userIf at 0x7bffd00.
12/10/08 Dec 10 7:42:34 AM kernel vmnet: VMNetConnect: returning port 0x7bffd00
12/10/08 Dec 10 7:42:34 AM kernel vmnet: Hub 0 does not exist, allocating memory.
12/10/08 Dec 10 7:42:34 AM kernel vmnet: Allocated hub 0x78cc000 for hubNum 0.
12/10/08 Dec 10 7:42:34 AM kernel vmnet: VMNET_SO_BINDTOHUB: port: paddr 00:50:56:f8:bc:98
12/10/08 Dec 10 7:42:34 AM kernel vmnet: Hub 0
12/10/08 Dec 10 7:42:34 AM kernel vmnet: Port 0
12/10/08 Dec 10 7:42:34 AM kernel vmnet: bridge-en1: got dev 0x7810a04
12/10/08 Dec 10 7:42:34 AM kernel vmnet: bridge-en1: wireless interface detected.
12/10/08 Dec 10 7:42:34 AM kernel vmnet: bridge-en1: up
12/10/08 Dec 10 7:42:34 AM kernel vmnet: bridge-en1: attached
12/10/08 Dec 10 7:42:34 AM kernel vmnet: VNetUserIfFree: freeing userIf at 0x7bffd00.
12/10/08 Dec 10 7:42:37 AM kernel [[0x850a000] Req OpCode 0c3f from: kernel_task (0) status: 0 state: 2 timeout: 10000] Bluetooth warning: An HCI Req timeout occurred.
12/10/08 Dec 10 7:42:37 AM kernel E:[AppleUSBBluetoothHCIController]WARNING !!!! [DeviceRequestCompleteHandler] error e00002ed
12/10/08 Dec 10 7:42:42 AM kernel [[0x8530000] Req OpCode 0c01 from: kernel_task (0) status: 0 state: 2 timeout: 5000] Bluetooth warning: An HCI Req timeout occurred.
12/10/08 Dec 10 7:42:42 AM kernel E:[AppleUSBBluetoothHCIController]WARNING !!!! [DeviceRequestCompleteHandler] error e00002ed
12/10/08 Dec 10 7:42:42 AM kernel E:[AppleUSBBluetoothHCIController][BulkOutWriteCompleteHandler] ERROR1: 0xe00002ed; sizeRem=00000009; isInactive = 0, suspended = 0
12/10/08 Dec 10 7:42:42 AM kernel E:[AppleUSBBluetoothHCIController][BulkInReadHandler] Received kIOReturnNotResponding error - retrying: 1.
12/10/08 Dec 10 7:42:42 AM kernel E:[AppleUSBBluetoothHCIController][BulkInReadHandler] immediate error (-536854449) queueing next read.
12/10/08 Dec 10 7:42:42 AM kernel IOBluetoothHCIController::terminateWL .. done
12/10/08 Dec 10 7:42:43 AM kernel [HCIController][configurePM] power parent ready after 1 tries
12/10/08 Dec 10 7:42:43 AM com.apple.UserEventAgent-Aqua[222] <CFArray 0x516760 [0xa02641a0]>{type = mutable-small, count = 4, values = (
12/10/08 Dec 10 7:42:43 AM com.apple.UserEventAgent-Aqua[222] 0 : <CFString 0x1
12/10/08 Dec 10 7:42:43 AM com.apple.UserEventAgent-Aqua[222] 6b8c0 [0xa02641a0]>{contents = "/System/Library/CoreServices/Menu Extras/TextInput.menu"}
12/10/08 Dec 10 7:42:43 AM com.apple.UserEventAgent-Aqua[222] 1 : <CFString 0x516680 [0xa02641a0]>{contents = "/System/Library/CoreServices/Menu Extras/Clock.menu"}
12/10/08 Dec 10 7:42:43 AM com.apple.UserEventAgent-Aqua[222] 2 : <CFString 0x5166c0 [0xa02641a0]>{contents = "/System/Library/CoreServices/Menu Extras/TimeMachine.menu"}
12/10/08 Dec 10 7:42:43 AM com.apple.UserEventAgent-Aqua[222] 3 : <CFString 0x516710 [0xa02641a0]>{contents = "/System/Library/CoreServices/Menu Extras/Bluetooth.menu"}
12/10/08 Dec 10 7:42:43 AM com.apple.UserEventAgent-Aqua[222] )}
12/10/08 Dec 10 7:55:29 AM ntpd[14] time reset +0.551550 s