X-Git-Url: https://git.saurik.com/apple/xnu.git/blobdiff_plain/7e41aa883dd258f888d0470250eead40a53ef1f5..5ba3f43ea354af8ad55bea84372a2bc834d8757c:/iokit/Kernel/IOPMrootDomain.cpp diff --git a/iokit/Kernel/IOPMrootDomain.cpp b/iokit/Kernel/IOPMrootDomain.cpp index 9a5ccd20b..a28aa990f 100644 --- a/iokit/Kernel/IOPMrootDomain.cpp +++ b/iokit/Kernel/IOPMrootDomain.cpp @@ -57,6 +57,8 @@ #include #include #include +#include +#include #include #include "IOServicePrivate.h" // _IOServiceInterestNotifier @@ -83,14 +85,23 @@ __END_DECLS #define LOG(x...) \ do { kprintf(LOG_PREFIX x); } while (false) +#if DEVELOPMENT #define DLOG(x...) do { \ if (kIOLogPMRootDomain & gIOKitDebug) \ kprintf(LOG_PREFIX x); \ + else \ + os_log(OS_LOG_DEFAULT, LOG_PREFIX x); \ } while (false) +#else +#define DLOG(x...) do { \ + if (kIOLogPMRootDomain & gIOKitDebug) \ + kprintf(LOG_PREFIX x); \ +} while (false) +#endif #define DMSG(x...) do { \ if (kIOLogPMRootDomain & gIOKitDebug) { \ - kprintf(LOG_PREFIX x); IOLog(x); \ + kprintf(LOG_PREFIX x); \ } \ } while (false) @@ -171,7 +182,6 @@ IOReturn OSKextSystemSleepOrWake( UInt32 ); } extern "C" ppnum_t pmap_find_phys(pmap_t pmap, addr64_t va); extern "C" addr64_t kvtophys(vm_offset_t va); -extern "C" int stack_snapshot_from_kernel(pid_t pid, void *buf, uint32_t size, uint32_t flags, unsigned *bytesTraced); static void idleSleepTimerExpired( thread_call_param_t, thread_call_param_t ); static void notifySystemShutdown( IOService * root, uint32_t messageType ); @@ -186,9 +196,10 @@ static const OSSymbol *sleepMessagePEFunction = NULL; #define kIOPMSystemCapabilitiesKey "System Capabilities" #define kIORequestWranglerIdleKey "IORequestIdle" -#define kDefaultWranglerIdlePeriod 25 // in milliseconds +#define kDefaultWranglerIdlePeriod 1000 // in milliseconds #define kIOSleepWakeDebugKey "Persistent-memory-note" +#define kIOEFIBootRomFailureKey "wake-failure" #define kRD_AllPowerSources (kIOPMSupportedOnAC \ | kIOPMSupportedOnBatt \ @@ -307,6 +318,14 @@ static UInt32 gWillShutdown = 0; static UInt32 gPagingOff = 0; static UInt32 gSleepWakeUUIDIsSet = false; static uint32_t gAggressivesState = 0; +static uint32_t gHaltTimeMaxLog; +static uint32_t gHaltTimeMaxPanic; +IOLock * gHaltLogLock; +static char * gHaltLog; +enum { kHaltLogSize = 2048 }; +static size_t gHaltLogPos; +static uint64_t gHaltStartTime; + uuid_string_t bootsessionuuid_string; @@ -325,6 +344,8 @@ struct timeval gIOLastWakeTime; static char gWakeReasonString[128]; static bool gWakeReasonSysctlRegistered = false; +static AbsoluteTime gIOLastWakeAbsTime; +static AbsoluteTime gIOLastSleepAbsTime; #if defined(__i386__) || defined(__x86_64__) static bool gSpinDumpBufferFull = false; @@ -347,10 +368,10 @@ enum { kInformableCount = 2 }; -const OSSymbol *gIOPMStatsApplicationResponseTimedOut; -const OSSymbol *gIOPMStatsApplicationResponseCancel; -const OSSymbol *gIOPMStatsApplicationResponseSlow; -const OSSymbol *gIOPMStatsApplicationResponsePrompt; +const OSSymbol *gIOPMStatsResponseTimedOut; +const OSSymbol *gIOPMStatsResponseCancel; +const OSSymbol *gIOPMStatsResponseSlow; +const OSSymbol *gIOPMStatsResponsePrompt; const OSSymbol *gIOPMStatsDriverPSChangeSlow; #define kBadPMFeatureID 0 @@ -435,9 +456,8 @@ public: static PMTraceWorker *tracer( IOPMrootDomain * ); void tracePCIPowerChange(change_t, IOService *, uint32_t, uint32_t); void tracePoint(uint8_t phase); - void tracePoint(uint8_t phase, uint8_t data8); void traceDetail(uint32_t detail); - void traceLoginWindowPhase(uint8_t phase); + void traceComponentWakeProgress(uint32_t component, uint32_t data); int recordTopLevelPCIDevice(IOService *); void RTC_TRACE(void); virtual bool serialize(OSSerialize *s) const APPLE_KEXT_OVERRIDE; @@ -445,16 +465,19 @@ public: IOPMTracePointHandler tracePointHandler; void * tracePointTarget; uint64_t getPMStatusCode(); + uint8_t getTracePhase(); + uint32_t getTraceData(); private: IOPMrootDomain *owner; - IOLock *pciMappingLock; + IOLock *pmTraceWorkerLock; OSArray *pciDeviceBitMappings; uint8_t addedToRegistry; uint8_t tracePhase; - uint8_t loginWindowPhase; - uint8_t traceData8; uint32_t traceData32; + uint8_t loginWindowData; + uint8_t coreDisplayData; + uint8_t coreGraphicsData; }; /* @@ -556,53 +579,115 @@ static void IOPMRootDomainWillShutdown(void) } } -extern "C" +extern "C" IONotifier * registerSleepWakeInterest(IOServiceInterestHandler handler, void * self, void * ref) { - IONotifier * registerSleepWakeInterest(IOServiceInterestHandler handler, void * self, void * ref) - { - return gRootDomain->registerInterest( gIOGeneralInterest, handler, self, ref ); - } + return gRootDomain->registerInterest( gIOGeneralInterest, handler, self, ref ); +} - IONotifier * registerPrioritySleepWakeInterest(IOServiceInterestHandler handler, void * self, void * ref) - { - return gRootDomain->registerInterest( gIOPriorityPowerStateInterest, handler, self, ref ); - } +extern "C" IONotifier * registerPrioritySleepWakeInterest(IOServiceInterestHandler handler, void * self, void * ref) +{ + return gRootDomain->registerInterest( gIOPriorityPowerStateInterest, handler, self, ref ); +} - IOReturn acknowledgeSleepWakeNotification(void * PMrefcon) - { - return gRootDomain->allowPowerChange ( (unsigned long)PMrefcon ); - } +extern "C" IOReturn acknowledgeSleepWakeNotification(void * PMrefcon) +{ + return gRootDomain->allowPowerChange ( (unsigned long)PMrefcon ); +} - IOReturn vetoSleepWakeNotification(void * PMrefcon) - { - return gRootDomain->cancelPowerChange ( (unsigned long)PMrefcon ); - } +extern "C" IOReturn vetoSleepWakeNotification(void * PMrefcon) +{ + return gRootDomain->cancelPowerChange ( (unsigned long)PMrefcon ); +} - IOReturn rootDomainRestart ( void ) - { - return gRootDomain->restartSystem(); +extern "C" IOReturn rootDomainRestart ( void ) +{ + return gRootDomain->restartSystem(); +} + +extern "C" IOReturn rootDomainShutdown ( void ) +{ + return gRootDomain->shutdownSystem(); +} + +static void halt_log_putc(char c) +{ + if (gHaltLogPos >= (kHaltLogSize - 1)) return; + gHaltLog[gHaltLogPos++] = c; +} + +extern "C" void +_doprnt_log(const char *fmt, + va_list *argp, + void (*putc)(char), + int radix); + +static int +halt_log(const char *fmt, ...) +{ + va_list listp; + + va_start(listp, fmt); + _doprnt_log(fmt, &listp, &halt_log_putc, 16); + va_end(listp); + + return (0); +} + +extern "C" void +halt_log_enter(const char * what, const void * pc, uint64_t time) +{ + uint64_t nano, millis; + + if (!gHaltLog) return; + absolutetime_to_nanoseconds(time, &nano); + millis = nano / 1000000ULL; + if (millis < 100) return; + + IOLockLock(gHaltLogLock); + if (pc) { + halt_log("%s: %qd ms @ 0x%lx, ", what, millis, VM_KERNEL_UNSLIDE(pc)); + OSKext::printKextsInBacktrace((vm_offset_t *) &pc, 1, &halt_log, + OSKext::kPrintKextsLock | OSKext::kPrintKextsUnslide | OSKext::kPrintKextsTerse); + } else { + halt_log("%s: %qd ms\n", what, millis, VM_KERNEL_UNSLIDE(pc)); } + IOLockUnlock(gHaltLogLock); +} - IOReturn rootDomainShutdown ( void ) +extern uint32_t gFSState; + +extern "C" void IOSystemShutdownNotification(void) +{ + uint64_t startTime; + + IOLockLock(gHaltLogLock); + if (!gHaltLog) { - return gRootDomain->shutdownSystem(); + gHaltLog = IONew(char, kHaltLogSize); + gHaltStartTime = mach_absolute_time(); + if (gHaltLog) halt_log_putc('\n'); } + IOLockUnlock(gHaltLogLock); - void IOSystemShutdownNotification(void) - { - IOPMRootDomainWillShutdown(); + startTime = mach_absolute_time(); + IOPMRootDomainWillShutdown(); + halt_log_enter("IOPMRootDomainWillShutdown", 0, mach_absolute_time() - startTime); #if HIBERNATION - IOHibernateSystemPostWake(); + startTime = mach_absolute_time(); + IOHibernateSystemPostWake(true); + halt_log_enter("IOHibernateSystemPostWake", 0, mach_absolute_time() - startTime); +#endif + if (OSCompareAndSwap(0, 1, &gPagingOff)) + { +#if !CONFIG_EMBEDDED + gRootDomain->handlePlatformHaltRestart(kPEPagingOff); #endif - if (OSCompareAndSwap(0, 1, &gPagingOff)) - { - gRootDomain->handlePlatformHaltRestart(kPEPagingOff); - } } - - int sync_internal(void); } + +extern "C" int sync_internal(void); + /* A device is always in the highest power state which satisfies its driver, its policy-maker, and any power children it has, but within the constraint @@ -681,6 +766,73 @@ void IOPMrootDomain::updateConsoleUsers(void) //****************************************************************************** +static void swdDebugSetupCallout( thread_call_param_t p0, thread_call_param_t p1 ) +{ + IOPMrootDomain * rootDomain = (IOPMrootDomain *) p0; + uint32_t notifyRef = (uint32_t)(uintptr_t) p1; + + rootDomain->swdDebugSetup(); + + if (p1) { + rootDomain->allowPowerChange(notifyRef); + } + DLOG("swdDebugSetupCallout finish\n"); +} + +void IOPMrootDomain::swdDebugSetup( ) +{ +#if HIBERNATION + static int32_t mem_only = -1; + if ((mem_only == -1) && + (PE_parse_boot_argn("swd_mem_only", &mem_only, sizeof(mem_only)) == false)) { + mem_only = 0; + } + + if ((mem_only == 1) || (gRootDomain->sleepWakeDebugIsWdogEnabled() == false)) { + return; + } + DLOG("swdDebugSetup state:%d\n", swd_DebugImageSetup); + if (swd_DebugImageSetup == FALSE) { + swd_DebugImageSetup = TRUE; + if (CAP_GAIN(kIOPMSystemCapabilityGraphics) || + (CAP_LOSS(kIOPMSystemCapabilityGraphics))) { + IOHibernateSystemPostWake(true); + } + IOOpenDebugDataFile(kSleepWakeStackBinFilename, SWD_BUF_SIZE); + } +#endif + + +} + +static void swdDebugTeardownCallout( thread_call_param_t p0, thread_call_param_t p1 ) +{ + IOPMrootDomain * rootDomain = (IOPMrootDomain *) p0; + uint32_t notifyRef = (uint32_t)(uintptr_t) p1; + + rootDomain->swdDebugTeardown(); + if (p1) { + rootDomain->allowPowerChange(notifyRef); + } + DLOG("swdDebugTeardownCallout finish\n"); +} + +void IOPMrootDomain::swdDebugTeardown( ) +{ + +#if HIBERNATION + DLOG("swdDebugTeardown state:%d\n", swd_DebugImageSetup); + if (swd_DebugImageSetup == TRUE) { + swd_DebugImageSetup = FALSE; + IOCloseDebugDataFile(); + } +#endif + + +} +//****************************************************************************** + + static void disk_sync_callout( thread_call_param_t p0, thread_call_param_t p1 ) { IOService * rootDomain = (IOService *) p0; @@ -692,11 +844,13 @@ static void disk_sync_callout( thread_call_param_t p0, thread_call_param_t p1 ) if (ON_STATE == powerState) { sync_internal(); + swdDebugSetupCallout(p0, NULL); } #if HIBERNATION else { - IOHibernateSystemPostWake(); + swdDebugTeardownCallout(p0, NULL); + IOHibernateSystemPostWake(false); if (gRootDomain) gRootDomain->sleepWakeDebugSaveSpinDumpFile(); @@ -708,31 +862,18 @@ static void disk_sync_callout( thread_call_param_t p0, thread_call_param_t p1 ) } //****************************************************************************** - -static void hib_debugSetup_callout( thread_call_param_t p0, thread_call_param_t p1 ) -{ - IOService * rootDomain = (IOService *) p0; - uint32_t notifyRef = (uint32_t)(uintptr_t) p1; - -#if HIBERNATION - IOOpenDebugDataFile(kSleepWakeStackBinFilename, SWD_BUF_SIZE); -#endif - - rootDomain->allowPowerChange(notifyRef); - DLOG("hib_debugSetup_callout finish\n"); -} -//****************************************************************************** - -static UInt32 computeDeltaTimeMS( const AbsoluteTime * startTime ) +static UInt32 computeDeltaTimeMS( const AbsoluteTime * startTime, AbsoluteTime * elapsedTime ) { AbsoluteTime endTime; UInt64 nano = 0; clock_get_uptime(&endTime); - if (CMP_ABSOLUTETIME(&endTime, startTime) > 0) + if (CMP_ABSOLUTETIME(&endTime, startTime) <= 0) *elapsedTime = 0; + else { SUB_ABSOLUTETIME(&endTime, startTime); absolutetime_to_nanoseconds(endTime, &nano); + *elapsedTime = endTime; } return (UInt32)(nano / 1000000ULL); @@ -749,12 +890,12 @@ sysctl_sleepwaketime SYSCTL_HANDLER_ARGS if (p == kernproc) { return sysctl_io_opaque(req, swt, sizeof(*swt), NULL); } else if(proc_is64bit(p)) { - struct user64_timeval t; + struct user64_timeval t = {}; t.tv_sec = swt->tv_sec; t.tv_usec = swt->tv_usec; return sysctl_io_opaque(req, &t, sizeof(t), NULL); } else { - struct user32_timeval t; + struct user32_timeval t = {}; t.tv_sec = swt->tv_sec; t.tv_usec = swt->tv_usec; return sysctl_io_opaque(req, &t, sizeof(t), NULL); @@ -769,6 +910,8 @@ static SYSCTL_PROC(_kern, OID_AUTO, waketime, CTLTYPE_STRUCT | CTLFLAG_RD | CTLFLAG_NOAUTO | CTLFLAG_KERN | CTLFLAG_LOCKED, &gIOLastWakeTime, 0, sysctl_sleepwaketime, "S,timeval", ""); +SYSCTL_QUAD(_kern, OID_AUTO, wake_abs_time, CTLFLAG_RD|CTLFLAG_LOCKED, &gIOLastWakeAbsTime, ""); +SYSCTL_QUAD(_kern, OID_AUTO, sleep_abs_time, CTLFLAG_RD|CTLFLAG_LOCKED, &gIOLastSleepAbsTime, ""); static int sysctl_willshutdown @@ -790,7 +933,9 @@ static SYSCTL_PROC(_kern, OID_AUTO, willshutdown, 0, 0, sysctl_willshutdown, "I", ""); extern struct sysctl_oid sysctl__kern_iokittest; +extern struct sysctl_oid sysctl__debug_iokit; +#if !CONFIG_EMBEDDED static int sysctl_progressmeterenable @@ -828,6 +973,7 @@ static SYSCTL_PROC(_kern, OID_AUTO, progressmeter, CTLTYPE_INT | CTLFLAG_RW | CTLFLAG_NOAUTO | CTLFLAG_KERN | CTLFLAG_LOCKED, 0, 0, sysctl_progressmeter, "I", ""); +#endif /* !CONFIG_EMBEDDED */ @@ -942,10 +1088,10 @@ bool IOPMrootDomain::start( IOService * nub ) gIOPMUserTriggeredFullWakeKey = OSSymbol::withCStringNoCopy(kIOPMUserTriggeredFullWakeKey); gIOPMUserIsActiveKey = OSSymbol::withCStringNoCopy(kIOPMUserIsActiveKey); - gIOPMStatsApplicationResponseTimedOut = OSSymbol::withCString(kIOPMStatsResponseTimedOut); - gIOPMStatsApplicationResponseCancel = OSSymbol::withCString(kIOPMStatsResponseCancel); - gIOPMStatsApplicationResponseSlow = OSSymbol::withCString(kIOPMStatsResponseSlow); - gIOPMStatsApplicationResponsePrompt = OSSymbol::withCString(kIOPMStatsResponsePrompt); + gIOPMStatsResponseTimedOut = OSSymbol::withCString(kIOPMStatsResponseTimedOut); + gIOPMStatsResponseCancel = OSSymbol::withCString(kIOPMStatsResponseCancel); + gIOPMStatsResponseSlow = OSSymbol::withCString(kIOPMStatsResponseSlow); + gIOPMStatsResponsePrompt = OSSymbol::withCString(kIOPMStatsResponsePrompt); gIOPMStatsDriverPSChangeSlow = OSSymbol::withCString(kIOPMStatsDriverPSChangeSlow); sleepSupportedPEFunction = OSSymbol::withCString("IOPMSetSleepSupported"); @@ -974,6 +1120,8 @@ bool IOPMrootDomain::start( IOService * nub ) PE_parse_boot_argn("darkwake", &gDarkWakeFlags, sizeof(gDarkWakeFlags)); PE_parse_boot_argn("noidle", &gNoIdleFlag, sizeof(gNoIdleFlag)); + PE_parse_boot_argn("haltmspanic", &gHaltTimeMaxPanic, sizeof(gHaltTimeMaxPanic)); + PE_parse_boot_argn("haltmslog", &gHaltTimeMaxLog, sizeof(gHaltTimeMaxLog)); queue_init(&aggressivesQueue); aggressivesThreadCall = thread_call_allocate(handleAggressivesFunction, this); @@ -983,6 +1131,7 @@ bool IOPMrootDomain::start( IOService * nub ) featuresDictLock = IOLockAlloc(); settingsCtrlLock = IOLockAlloc(); wakeEventLock = IOLockAlloc(); + gHaltLogLock = IOLockAlloc(); setPMRootDomain(this); extraSleepTimer = thread_call_allocate( @@ -992,10 +1141,12 @@ bool IOPMrootDomain::start( IOService * nub ) diskSyncCalloutEntry = thread_call_allocate( &disk_sync_callout, (thread_call_param_t) this); - hibDebugSetupEntry = thread_call_allocate( - &hib_debugSetup_callout, + swdDebugSetupEntry = thread_call_allocate( + &swdDebugSetupCallout, + (thread_call_param_t) this); + swdDebugTearDownEntry = thread_call_allocate( + &swdDebugTeardownCallout, (thread_call_param_t) this); - updateConsoleUsersEntry = thread_call_allocate( &updateConsoleUsersCallout, (thread_call_param_t) this); @@ -1017,6 +1168,7 @@ bool IOPMrootDomain::start( IOService * nub ) userDisabledAllSleep = false; systemBooting = true; + idleSleepEnabled = false; sleepSlider = 0; idleSleepTimerPending = false; wrangler = NULL; @@ -1082,16 +1234,14 @@ bool IOPMrootDomain::start( IOService * nub ) preventSystemSleepList = OSSet::withCapacity(2); PMinit(); // creates gIOPMWorkLoop + gIOPMWorkLoop = getIOPMWorkloop(); // Create IOPMPowerStateQueue used to queue external power // events, and to handle those events on the PM work loop. pmPowerStateQueue = IOPMPowerStateQueue::PMPowerStateQueue( this, OSMemberFunctionCast(IOEventSource::Action, this, &IOPMrootDomain::dispatchPowerEvent)); - getPMworkloop()->addEventSource(pmPowerStateQueue); -#ifdef CHECK_THREAD_CONTEXT - gIOPMWorkLoop = getPMworkloop(); -#endif + gIOPMWorkLoop->addEventSource(pmPowerStateQueue); // create our power parent patriarch = new IORootParent; @@ -1167,11 +1317,14 @@ bool IOPMrootDomain::start( IOService * nub ) sysctl_register_oid(&sysctl__kern_waketime); sysctl_register_oid(&sysctl__kern_willshutdown); sysctl_register_oid(&sysctl__kern_iokittest); + sysctl_register_oid(&sysctl__debug_iokit); sysctl_register_oid(&sysctl__hw_targettype); +#if !CONFIG_EMBEDDED sysctl_register_oid(&sysctl__kern_progressmeterenable); sysctl_register_oid(&sysctl__kern_progressmeter); sysctl_register_oid(&sysctl__kern_wakereason); +#endif /* !CONFIG_EMBEDDED */ sysctl_register_oid(&sysctl__kern_consoleoptions); sysctl_register_oid(&sysctl__kern_progressoptions); @@ -1209,7 +1362,9 @@ IOReturn IOPMrootDomain::setProperties( OSObject * props_obj ) const OSSymbol *idle_seconds_string = OSSymbol::withCString("System Idle Seconds"); const OSSymbol *sleepdisabled_string = OSSymbol::withCString("SleepDisabled"); const OSSymbol *ondeck_sleepwake_uuid_string = OSSymbol::withCString(kIOPMSleepWakeUUIDKey); - const OSSymbol *loginwindow_tracepoint_string = OSSymbol::withCString(kIOPMLoginWindowSecurityDebugKey); + const OSSymbol *loginwindow_progress_string = OSSymbol::withCString(kIOPMLoginWindowProgressKey); + const OSSymbol *coredisplay_progress_string = OSSymbol::withCString(kIOPMCoreDisplayProgressKey); + const OSSymbol *coregraphics_progress_string = OSSymbol::withCString(kIOPMCoreGraphicsProgressKey); #if HIBERNATION const OSSymbol *hibernatemode_string = OSSymbol::withCString(kIOHibernateModeKey); const OSSymbol *hibernatefile_string = OSSymbol::withCString(kIOHibernateFileKey); @@ -1290,10 +1445,29 @@ IOReturn IOPMrootDomain::setProperties( OSObject * props_obj ) obj->retain(); pmPowerStateQueue->submitPowerEvent(kPowerEventQueueSleepWakeUUID, (void *)obj); } - else if (key->isEqualTo(loginwindow_tracepoint_string)) + else if (key->isEqualTo(loginwindow_progress_string)) + { + if (pmTracer && (n = OSDynamicCast(OSNumber, obj))) { + uint32_t data = n->unsigned32BitValue(); + pmTracer->traceComponentWakeProgress(kIOPMLoginWindowProgress, data); + kdebugTrace(kPMLogComponentWakeProgress, 0, kIOPMLoginWindowProgress, data); + } + } + else if (key->isEqualTo(coredisplay_progress_string)) + { + if (pmTracer && (n = OSDynamicCast(OSNumber, obj))) { + uint32_t data = n->unsigned32BitValue(); + pmTracer->traceComponentWakeProgress(kIOPMCoreDisplayProgress, data); + kdebugTrace(kPMLogComponentWakeProgress, 0, kIOPMCoreDisplayProgress, data); + } + } + else if (key->isEqualTo(coregraphics_progress_string)) { - if (pmTracer && (n = OSDynamicCast(OSNumber, obj))) - pmTracer->traceLoginWindowPhase(n->unsigned8BitValue()); + if (pmTracer && (n = OSDynamicCast(OSNumber, obj))) { + uint32_t data = n->unsigned32BitValue(); + pmTracer->traceComponentWakeProgress(kIOPMCoreGraphicsProgress, data); + kdebugTrace(kPMLogComponentWakeProgress, 0, kIOPMCoreGraphicsProgress, data); + } } else if (key->isEqualTo(kIOPMDeepSleepEnabledKey) || key->isEqualTo(kIOPMDestroyFVKeyOnStandbyKey) || @@ -1304,6 +1478,7 @@ IOReturn IOPMrootDomain::setProperties( OSObject * props_obj ) setProperty(key, b); } else if (key->isEqualTo(kIOPMDeepSleepDelayKey) || + key->isEqualTo(kIOPMDeepSleepTimerKey) || key->isEqualTo(kIOPMAutoPowerOffDelayKey) || key->isEqualTo(kIOPMAutoPowerOffTimerKey)) { @@ -1372,7 +1547,9 @@ exit: if(idle_seconds_string) idle_seconds_string->release(); if(sleepdisabled_string) sleepdisabled_string->release(); if(ondeck_sleepwake_uuid_string) ondeck_sleepwake_uuid_string->release(); - if(loginwindow_tracepoint_string) loginwindow_tracepoint_string->release(); + if(loginwindow_progress_string) loginwindow_progress_string->release(); + if(coredisplay_progress_string) coredisplay_progress_string->release(); + if(coregraphics_progress_string) coregraphics_progress_string->release(); #if HIBERNATION if(hibernatemode_string) hibernatemode_string->release(); if(hibernatefile_string) hibernatefile_string->release(); @@ -1844,7 +2021,7 @@ void IOPMrootDomain::broadcastAggressives( if (!connect || !connect->getReadyFlag()) continue; - if ((service = (IOService *) connect->copyChildEntry(gIOPowerPlane))) + if ((service = OSDynamicCast(IOService, connect->copyChildEntry(gIOPowerPlane)))) { if (service->assertPMDriverCall(&callEntry)) { @@ -1915,11 +2092,11 @@ void IOPMrootDomain::cancelIdleSleepTimer( void ) thread_call_cancel(extraSleepTimer); idleSleepTimerPending = false; - if (!assertOnWakeSecs && systemWakeTime) { + if (!assertOnWakeSecs && gIOLastWakeAbsTime) { AbsoluteTime now; clock_usec_t microsecs; clock_get_uptime(&now); - SUB_ABSOLUTETIME(&now, &systemWakeTime); + SUB_ABSOLUTETIME(&now, &gIOLastWakeAbsTime); absolutetime_to_microtime(now, &assertOnWakeSecs, µsecs); if (assertOnWakeReport) { HISTREPORT_TALLYVALUE(assertOnWakeReport, (int64_t)assertOnWakeSecs); @@ -1949,9 +2126,9 @@ static void idleSleepTimerExpired( void IOPMrootDomain::handleSleepTimerExpiration( void ) { - if (!getPMworkloop()->inGate()) + if (!gIOPMWorkLoop->inGate()) { - getPMworkloop()->runAction( + gIOPMWorkLoop->runAction( OSMemberFunctionCast(IOWorkLoop::Action, this, &IOPMrootDomain::handleSleepTimerExpiration), this); @@ -1986,7 +2163,7 @@ uint32_t IOPMrootDomain::getTimeToIdleSleep( void ) uint32_t minutesSinceUserInactive = 0; uint32_t sleepDelay = 0; - if (sleepSlider == 0) + if (!idleSleepEnabled) return 0xffffffff; if (userActivityTime) @@ -2107,6 +2284,9 @@ IOReturn IOPMrootDomain::privateSleepSystem( uint32_t sleepReason ) void IOPMrootDomain::powerChangeDone( unsigned long previousPowerState ) { +#if !__i386__ && !__x86_64__ + uint64_t timeSinceReset = 0; +#endif uint64_t now; ASSERT_GATED(); DLOG("PowerChangeDone: %u->%u\n", @@ -2131,6 +2311,7 @@ void IOPMrootDomain::powerChangeDone( unsigned long previousPowerState ) gIOLastSleepTime.tv_usec = microsecs; gIOLastWakeTime.tv_sec = 0; gIOLastWakeTime.tv_usec = 0; + gIOLastSleepAbsTime = now; if (wake2DarkwakeDelay && sleepDelaysReport) { clock_usec_t microsecs; @@ -2164,12 +2345,15 @@ void IOPMrootDomain::powerChangeDone( unsigned long previousPowerState ) } assertOnWakeSecs = 0; ((IOService *)this)->stop_watchdog_timer(); //14456299 + lowBatteryCondition = false; + getPlatform()->sleepKernel(); // The CPU(s) are off at this point, // Code will resume execution here upon wake. - clock_get_uptime(&systemWakeTime); + clock_get_uptime(&gIOLastWakeAbsTime); + IOLog("gIOLastWakeAbsTime: %lld\n", gIOLastWakeAbsTime); _highestCapability = 0; ((IOService *)this)->start_watchdog_timer(); //14456299 @@ -2185,7 +2369,7 @@ void IOPMrootDomain::powerChangeDone( unsigned long previousPowerState ) clock_sec_t wakeSecs; clock_usec_t wakeMicrosecs; - clock_initialize_calendar(); + clock_wakeup_calendar(); clock_get_calendar_microtime(&wakeSecs, &wakeMicrosecs); gIOLastWakeTime.tv_sec = wakeSecs; @@ -2196,20 +2380,14 @@ void IOPMrootDomain::powerChangeDone( unsigned long previousPowerState ) LOG("System %sWake\n", gIOHibernateState ? "SafeSleep " : ""); #endif - // log system wake - PMDebug(kPMLogSystemWake, 0, 0); - lowBatteryCondition = false; lastSleepReason = 0; _lastDebugWakeSeconds = _debugWakeSeconds; _debugWakeSeconds = 0; _scheduledAlarms = 0; -#ifndef __LP64__ - systemWake(); -#endif - #if defined(__i386__) || defined(__x86_64__) + kdebugTrace(kPMLogSystemWake, 0, 0, 0); wranglerTickled = false; graphicsSuppressed = false; darkWakePostTickle = false; @@ -2356,6 +2534,9 @@ void IOPMrootDomain::powerChangeDone( unsigned long previousPowerState ) } } #else /* !__i386__ && !__x86_64__ */ + timeSinceReset = ml_get_time_since_reset(); + + kdebugTrace(kPMLogSystemWake, 0, timeSinceReset >> 32, timeSinceReset); // stay awake for at least 30 seconds wranglerTickled = true; fullWakeReason = kFullWakeReasonLocalUser; @@ -2464,6 +2645,7 @@ bool IOPMrootDomain::updatePreventIdleSleepList( #if defined(__i386__) || defined(__x86_64__) if (addNotRemove && (service == wrangler) && !checkSystemCanSustainFullWake()) { + DLOG("Cannot cancel idle sleep\n"); return false; // do not idle-cancel } #endif @@ -2471,6 +2653,15 @@ bool IOPMrootDomain::updatePreventIdleSleepList( return true; } +//****************************************************************************** +// startSpinDump +//****************************************************************************** + +void IOPMrootDomain::startSpinDump(uint32_t spindumpKind) +{ + messageClients(kIOPMMessageLaunchBootSpinDump, (void *)(uintptr_t)spindumpKind); +} + //****************************************************************************** // preventSystemSleepListUpdate // @@ -2492,11 +2683,11 @@ void IOPMrootDomain::updatePreventSystemSleepList( preventSystemSleepList->setObject(service); DLOG("prevent system sleep list: %s+ (%u)\n", service->getName(), preventSystemSleepList->getCount()); - if (!assertOnWakeSecs && systemWakeTime) { + if (!assertOnWakeSecs && gIOLastWakeAbsTime) { AbsoluteTime now; clock_usec_t microsecs; clock_get_uptime(&now); - SUB_ABSOLUTETIME(&now, &systemWakeTime); + SUB_ABSOLUTETIME(&now, &gIOLastWakeAbsTime); absolutetime_to_microtime(now, &assertOnWakeSecs, µsecs); if (assertOnWakeReport) { HISTREPORT_TALLYVALUE(assertOnWakeReport, (int64_t)assertOnWakeSecs); @@ -2529,9 +2720,9 @@ void IOPMrootDomain::copySleepPreventersList(OSArray **idleSleepList, OSArray ** OSObject *object = NULL; OSArray *array = NULL; - if (!getPMworkloop()->inGate()) + if (!gIOPMWorkLoop->inGate()) { - getPMworkloop()->runAction( + gIOPMWorkLoop->runAction( OSMemberFunctionCast(IOWorkLoop::Action, this, &IOPMrootDomain::IOPMrootDomain::copySleepPreventersList), this, (void *)idleSleepList, (void *)systemSleepList); @@ -2595,21 +2786,23 @@ bool IOPMrootDomain::tellChangeDown( unsigned long stateNum ) tracePoint( kIOPMTracePointSleepPriorityClients ); } - if ((SLEEP_STATE == stateNum) && !ignoreTellChangeDown) - { + if (!ignoreTellChangeDown) { userActivityAtSleep = userActivityCount; - hibernateAborted = false; DLOG("tellChangeDown::userActivityAtSleep %d\n", userActivityAtSleep); - // Direct callout into OSKext so it can disable kext unloads - // during sleep/wake to prevent deadlocks. - OSKextSystemSleepOrWake( kIOMessageSystemWillSleep ); + if (SLEEP_STATE == stateNum) { + hibernateAborted = false; + + // Direct callout into OSKext so it can disable kext unloads + // during sleep/wake to prevent deadlocks. + OSKextSystemSleepOrWake( kIOMessageSystemWillSleep ); - IOService::updateConsoleUsers(NULL, kIOMessageSystemWillSleep); + IOService::updateConsoleUsers(NULL, kIOMessageSystemWillSleep); - // Two change downs are sent by IOServicePM. Ignore the 2nd. - // But tellClientsWithResponse() must be called for both. - ignoreTellChangeDown = true; + // Two change downs are sent by IOServicePM. Ignore the 2nd. + // But tellClientsWithResponse() must be called for both. + ignoreTellChangeDown = true; + } } return super::tellClientsWithResponse( kIOMessageSystemWillSleep ); @@ -2696,7 +2889,7 @@ void IOPMrootDomain::systemDidNotSleep( void ) if (!wrangler) { - if (idleSeconds) + if (idleSleepEnabled) { // stay awake for at least idleSeconds startIdleSleepTimer(idleSeconds); @@ -2704,7 +2897,7 @@ void IOPMrootDomain::systemDidNotSleep( void ) } else { - if (sleepSlider && !userIsActive) + if (idleSleepEnabled && !userIsActive) { // Manually start the idle sleep timer besides waiting for // the user to become inactive. @@ -2804,6 +2997,26 @@ void IOPMrootDomain::tellChangeUp( unsigned long stateNum ) } } +#define CAP_WILL_CHANGE_TO_OFF(params, flag) \ + (((params)->changeFlags & kIOPMSystemCapabilityWillChange) && \ + ((params)->fromCapabilities & (flag)) && \ + (((params)->toCapabilities & (flag)) == 0)) + +#define CAP_DID_CHANGE_TO_ON(params, flag) \ + (((params)->changeFlags & kIOPMSystemCapabilityDidChange) && \ + ((params)->toCapabilities & (flag)) && \ + (((params)->fromCapabilities & (flag)) == 0)) + +#define CAP_DID_CHANGE_TO_OFF(params, flag) \ + (((params)->changeFlags & kIOPMSystemCapabilityDidChange) && \ + ((params)->fromCapabilities & (flag)) && \ + (((params)->toCapabilities & (flag)) == 0)) + +#define CAP_WILL_CHANGE_TO_ON(params, flag) \ + (((params)->changeFlags & kIOPMSystemCapabilityWillChange) && \ + ((params)->toCapabilities & (flag)) && \ + (((params)->fromCapabilities & (flag)) == 0)) + //****************************************************************************** // sysPowerDownHandler // @@ -2825,21 +3038,13 @@ IOReturn IOPMrootDomain::sysPowerDownHandler( if (messageType == kIOMessageSystemWillSleep) { #if HIBERNATION - static int32_t mem_only = -1; IOPowerStateChangeNotification *notify = - (IOPowerStateChangeNotification *)messageArgs; + (IOPowerStateChangeNotification *)messageArgs; - if ((mem_only == -1) && - (PE_parse_boot_argn("swd_mem_only", &mem_only, sizeof(mem_only)) == false)) { - mem_only = 0; - } - if ((mem_only != 1) && (gRootDomain->sleepWakeDebugIsWdogEnabled())) - { - notify->returnValue = 30 * 1000 * 1000; - thread_call_enter1( - gRootDomain->hibDebugSetupEntry, - (thread_call_param_t)(uintptr_t) notify->powerRef); - } + notify->returnValue = 30 * 1000 * 1000; + thread_call_enter1( + gRootDomain->swdDebugSetupEntry, + (thread_call_param_t)(uintptr_t) notify->powerRef); #endif } else if (messageType == kIOMessageSystemCapabilityChange) @@ -2858,12 +3063,14 @@ IOReturn IOPMrootDomain::sysPowerDownHandler( params->fromCapabilities, params->toCapabilities, params->changeFlags); - if ((params->changeFlags & kIOPMSystemCapabilityWillChange) && - (params->fromCapabilities & kIOPMSystemCapabilityCPU) && - (params->toCapabilities & kIOPMSystemCapabilityCPU) == 0) + if (CAP_WILL_CHANGE_TO_OFF(params, kIOPMSystemCapabilityCPU)) { // We will ack within 20 seconds params->maxWaitForReply = 20 * 1000 * 1000; + + // Remove EFI/BootRom's previous wake's failure data + PERemoveNVRAMProperty(kIOEFIBootRomFailureKey); + #if HIBERNATION gRootDomain->evaluateSystemSleepPolicyEarly(); @@ -2900,20 +3107,36 @@ IOReturn IOPMrootDomain::sysPowerDownHandler( gRootDomain->diskSyncCalloutEntry, (thread_call_param_t)(uintptr_t) params->notifyRef); } - else - if ((params->changeFlags & kIOPMSystemCapabilityDidChange) && - (params->toCapabilities & kIOPMSystemCapabilityCPU) && - (params->fromCapabilities & kIOPMSystemCapabilityCPU) == 0) - { #if HIBERNATION + else if (CAP_DID_CHANGE_TO_ON(params, kIOPMSystemCapabilityCPU)) + { // We will ack within 110 seconds params->maxWaitForReply = 110 * 1000 * 1000; thread_call_enter1( gRootDomain->diskSyncCalloutEntry, (thread_call_param_t)(uintptr_t) params->notifyRef); -#endif } + else if (CAP_WILL_CHANGE_TO_OFF(params, kIOPMSystemCapabilityGraphics) || + CAP_WILL_CHANGE_TO_ON(params, kIOPMSystemCapabilityGraphics)) + { + // WillChange for Full wake -> Darkwake + params->maxWaitForReply = 30 * 1000 * 1000; + thread_call_enter1( + gRootDomain->swdDebugSetupEntry, + (thread_call_param_t)(uintptr_t) params->notifyRef); + } + else if (CAP_DID_CHANGE_TO_OFF(params, kIOPMSystemCapabilityGraphics) || + CAP_DID_CHANGE_TO_ON(params, kIOPMSystemCapabilityGraphics)) + { + // DidChange for Full wake -> Darkwake + params->maxWaitForReply = 30 * 1000 * 1000; + thread_call_enter1( + gRootDomain->swdDebugTearDownEntry, + (thread_call_param_t)(uintptr_t) params->notifyRef); + + } +#endif ret = kIOReturnSuccess; } @@ -3108,7 +3331,9 @@ void IOPMrootDomain::willNotifyPowerChildren( IOPMPowerStateIndex newPowerState tasks_system_suspend(tasksSuspended); clock_interval_to_deadline(10, kSecondScale, &deadline); +#if !CONFIG_EMBEDDED vm_pageout_wait(AbsoluteTime_to_scalar(&deadline)); +#endif /* !CONFIG_EMBEDDED */ } #if HIBERNATION @@ -3530,7 +3755,7 @@ IOReturn IOPMrootDomain::setPMSetting( fPMSettingsDict->setObject(type, object); // Prep all PMSetting objects with the given 'type' for callout. - array = (const OSArray *) settingsCallbacks->getObject(type); + array = OSDynamicCast(OSArray, settingsCallbacks->getObject(type)); if (!array || ((capacity = array->getCount()) == 0)) goto unlock_exit; @@ -3683,7 +3908,7 @@ IOReturn IOPMrootDomain::registerPMSettingController( PMSETTING_LOCK(); for (i=0; settings[i]; i++) { - list = (OSArray *) settingsCallbacks->getObject(settings[i]); + list = OSDynamicCast(OSArray, settingsCallbacks->getObject(settings[i])); if (!list) { // New array of callbacks for this setting list = OSArray::withCapacity(1); @@ -3748,7 +3973,7 @@ void IOPMrootDomain::deregisterPMSettingObject( PMSettingObject * pmso ) { while ((sym = OSDynamicCast(OSSymbol, iter->getNextObject()))) { - array = (OSArray *) settingsCallbacks->getObject(sym); + array = OSDynamicCast(OSArray, settingsCallbacks->getObject(sym)); index = array->getNextIndexOfObject(pmso, 0); if (-1 != index) { array->removeObject(index); @@ -3800,9 +4025,9 @@ void IOPMrootDomain::informCPUStateChange( varInfoStruct.varType = vBool; varInfoStruct.varInitValue = value; varInfoStruct.varCurValue = value; - strncpy( (char *)varInfoStruct.varName, + strlcpy( (char *)varInfoStruct.varName, (const char *)varNameStr, - strlen(varNameStr) + 1 ); + sizeof(varInfoStruct.varName)); // Set! pmCPUret = pmCPUControl( PMIOCSETVARINFO, (void *)&varInfoStruct ); @@ -3896,6 +4121,7 @@ bool IOPMrootDomain::evaluateSystemSleepPolicy( uint32_t standbyDelay = 0; uint32_t powerOffDelay = 0; uint32_t powerOffTimer = 0; + uint32_t standbyTimer = 0; uint32_t mismatch; bool standbyEnabled; bool powerOffEnabled; @@ -3915,9 +4141,11 @@ bool IOPMrootDomain::evaluateSystemSleepPolicy( && (getProperty(kIOPMAutoPowerOffEnabledKey) == kOSBooleanTrue)); if (!getSleepOption(kIOPMAutoPowerOffTimerKey, &powerOffTimer)) powerOffTimer = powerOffDelay; + if (!getSleepOption(kIOPMDeepSleepTimerKey, &standbyTimer)) + standbyTimer = standbyDelay; - DLOG("phase %d, standby %d delay %u, poweroff %d delay %u timer %u, hibernate 0x%x\n", - sleepPhase, standbyEnabled, standbyDelay, + DLOG("phase %d, standby %d delay %u timer %u, poweroff %d delay %u timer %u, hibernate 0x%x\n", + sleepPhase, standbyEnabled, standbyDelay, standbyTimer, powerOffEnabled, powerOffDelay, powerOffTimer, *hibMode); // pmset level overrides @@ -3953,10 +4181,15 @@ bool IOPMrootDomain::evaluateSystemSleepPolicy( currentFactors |= kIOPMSleepFactorACPower; if (lowBatteryCondition) currentFactors |= kIOPMSleepFactorBatteryLow; - if (!standbyDelay) + if (!standbyDelay || !standbyTimer) currentFactors |= kIOPMSleepFactorStandbyNoDelay; - if (!standbyEnabled) + if (standbyNixed || !standbyEnabled) currentFactors |= kIOPMSleepFactorStandbyDisabled; + if (resetTimers) + { + currentFactors |= kIOPMSleepFactorLocalUserActivity; + currentFactors &= ~kIOPMSleepFactorSleepTimerWake; + } if (getPMAssertionLevel(kIOPMDriverAssertionUSBExternalDeviceBit) != kIOPMDriverAssertionLevelOff) currentFactors |= kIOPMSleepFactorUSBExternalDevice; @@ -4013,6 +4246,7 @@ bool IOPMrootDomain::evaluateSystemSleepPolicy( gSleepPolicyVars->sleepReason = lastSleepReason; gSleepPolicyVars->sleepPhase = sleepPhase; gSleepPolicyVars->standbyDelay = standbyDelay; + gSleepPolicyVars->standbyTimer = standbyTimer; gSleepPolicyVars->poweroffDelay = powerOffDelay; gSleepPolicyVars->scheduledAlarms = _scheduledAlarms | _userScheduledAlarm; gSleepPolicyVars->poweroffTimer = powerOffTimer; @@ -4201,36 +4435,56 @@ void IOPMrootDomain::evaluateSystemSleepPolicyFinal( void ) { IOPMSystemSleepParameters params; OSData * paramsData; - + bool wakeNow; // Evaluate sleep policy after sleeping drivers but before platform sleep. DLOG("%s\n", __FUNCTION__); bzero(¶ms, sizeof(params)); + wakeNow = false; if (evaluateSystemSleepPolicy(¶ms, kIOPMSleepPhase2, &hibernateMode)) { - if ((hibernateDisabled || hibernateAborted) && + if ((kIOPMSleepTypeStandby == params.sleepType) + && gIOHibernateStandbyDisabled && gSleepPolicyVars + && (!(kIOPMSleepFactorStandbyForced & gSleepPolicyVars->sleepFactors))) + { + standbyNixed = true; + wakeNow = true; + } + if (wakeNow + || ((hibernateDisabled || hibernateAborted) && (getSleepTypeAttributes(params.sleepType) & - kIOPMSleepAttributeHibernateSetup)) + kIOPMSleepAttributeHibernateSetup))) { // Final evaluation picked a state requiring hibernation, - // but hibernate setup was skipped. Arm a short sleep using + // but hibernate isn't going to proceed. Arm a short sleep using // the early non-hibernate sleep parameters. - // Set hibernateRetry flag to force hibernate setup on the - // next sleep. - bcopy(&gEarlySystemSleepParams, ¶ms, sizeof(params)); params.sleepType = kIOPMSleepTypeAbortedSleep; params.ecWakeTimer = 1; - hibernateRetry = true; - DLOG("wake in %u secs for hibernateDisabled %d, hibernateAborted %d\n", - params.ecWakeTimer, hibernateDisabled, hibernateAborted); + if (standbyNixed) + { + resetTimers = true; + } + else + { + // Set hibernateRetry flag to force hibernate setup on the + // next sleep. + hibernateRetry = true; + } + DLOG("wake in %u secs for hibernateDisabled %d, hibernateAborted %d, standbyNixed %d\n", + params.ecWakeTimer, hibernateDisabled, hibernateAborted, standbyNixed); } else { hibernateRetry = false; } + if (kIOPMSleepTypeAbortedSleep != params.sleepType) + { + resetTimers = false; + } + paramsData = OSData::withBytes(¶ms, sizeof(params)); if (paramsData) { @@ -4305,11 +4559,11 @@ bool IOPMrootDomain::getSleepOption( const char * key, uint32_t * option ) if (optionsProp) optionsProp->release(); - return true; + return ok; } #endif /* HIBERNATION */ -IOReturn IOPMrootDomain::getSystemSleepType( uint32_t * sleepType ) +IOReturn IOPMrootDomain::getSystemSleepType( uint32_t * sleepType, uint32_t * standbyTimer ) { #if HIBERNATION IOPMSystemSleepParameters params; @@ -4322,7 +4576,7 @@ IOReturn IOPMrootDomain::getSystemSleepType( uint32_t * sleepType ) OSMemberFunctionCast(IOWorkLoop::Action, this, &IOPMrootDomain::getSystemSleepType), (OSObject *) this, - (void *) sleepType); + (void *) sleepType, (void *) standbyTimer); return ret; } @@ -4333,6 +4587,11 @@ IOReturn IOPMrootDomain::getSystemSleepType( uint32_t * sleepType ) if (ok) { *sleepType = params.sleepType; + if (!getSleepOption(kIOPMDeepSleepTimerKey, standbyTimer) && + !getSleepOption(kIOPMDeepSleepDelayKey, standbyTimer)) { + DLOG("Standby delay is not set\n"); + *standbyTimer = 0; + } return kIOReturnSuccess; } #endif @@ -4362,7 +4621,7 @@ platformHaltRestartApplier( OSObject * object, void * context ) { IOPowerStateChangeNotification notify; HaltRestartApplierContext * ctx; - AbsoluteTime startTime; + AbsoluteTime startTime, elapsedTime; uint32_t deltaTime; ctx = (HaltRestartApplierContext *) context; @@ -4375,7 +4634,7 @@ platformHaltRestartApplier( OSObject * object, void * context ) clock_get_uptime(&startTime); ctx->RootDomain->messageClient( ctx->MessageType, object, (void *)¬ify ); - deltaTime = computeDeltaTimeMS(&startTime); + deltaTime = computeDeltaTimeMS(&startTime, &elapsedTime); if ((deltaTime > kPMHaltTimeoutMS) || (gIOKitDebug & kIOLogPMRootDomain)) @@ -4390,6 +4649,7 @@ platformHaltRestartApplier( OSObject * object, void * context ) { LOG("%s handler %p took %u ms\n", ctx->LogString, OBFUSCATE(notifier->handler), deltaTime); + halt_log_enter(ctx->LogString, (const void *) notifier->handler, elapsedTime); } } @@ -4407,7 +4667,7 @@ static void quiescePowerTreeCallback( void * target, void * param ) void IOPMrootDomain::handlePlatformHaltRestart( UInt32 pe_type ) { HaltRestartApplierContext ctx; - AbsoluteTime startTime; + AbsoluteTime startTime, elapsedTime; uint32_t deltaTime; memset(&ctx, 0, sizeof(ctx)); @@ -4483,13 +4743,28 @@ void IOPMrootDomain::handlePlatformHaltRestart( UInt32 pe_type ) } } IOLockUnlock(gPMHaltLock); - - deltaTime = computeDeltaTimeMS(&quiesceTime); + deltaTime = computeDeltaTimeMS(&quiesceTime, &elapsedTime); DLOG("PM quiesce took %u ms\n", deltaTime); + halt_log_enter("Quiesce", NULL, elapsedTime); } - deltaTime = computeDeltaTimeMS(&startTime); + deltaTime = computeDeltaTimeMS(&startTime, &elapsedTime); LOG("%s all drivers took %u ms\n", ctx.LogString, deltaTime); + + halt_log_enter(ctx.LogString, NULL, elapsedTime); + if (gHaltLog) gHaltLog[gHaltLogPos] = 0; + + deltaTime = computeDeltaTimeMS(&gHaltStartTime, &elapsedTime); + LOG("%s total %u ms\n", ctx.LogString, deltaTime); + + if (gHaltLog && gHaltTimeMaxLog && (deltaTime >= gHaltTimeMaxLog)) + { + printf("%s total %d ms:%s\n", ctx.LogString, deltaTime, gHaltLog); + } + if (gHaltLog && gHaltTimeMaxPanic && (deltaTime >= gHaltTimeMaxPanic)) + { + panic("%s total %d ms:%s\n", ctx.LogString, deltaTime, gHaltLog); + } } //****************************************************************************** @@ -4800,15 +5075,6 @@ void IOPMrootDomain::handleOurPowerChangeStart( _pendingCapability = 0; capabilityLoss = true; - // Clear previous stats - IOLockLock(pmStatsLock); - if (pmStatsAppResponses) - { - pmStatsAppResponses->release(); - pmStatsAppResponses = OSArray::withCapacity(5); - } - IOLockUnlock(pmStatsLock); - } else if (kSystemTransitionNewCapClient != _systemTransitionType) { @@ -4846,6 +5112,16 @@ void IOPMrootDomain::handleOurPowerChangeStart( // Full to Dark transition. if (CAP_LOSS(kIOPMSystemCapabilityGraphics)) { + // Clear previous stats + IOLockLock(pmStatsLock); + if (pmStatsAppResponses) + { + pmStatsAppResponses->release(); + pmStatsAppResponses = OSArray::withCapacity(5); + } + IOLockUnlock(pmStatsLock); + + tracePoint( kIOPMTracePointDarkWakeEntry ); *inOutChangeFlags |= kIOPMSyncTellPowerDown; _systemMessageClientMask = kSystemMessageClientPowerd | @@ -4869,6 +5145,8 @@ void IOPMrootDomain::handleOurPowerChangeStart( clock_get_uptime(&ts_sleepStart); DLOG("sleepDelaysReport f->9 start at 0x%llx\n", ts_sleepStart); } + + wranglerTickled = false; } } @@ -4878,13 +5156,16 @@ void IOPMrootDomain::handleOurPowerChangeStart( { // Beginning of a system sleep transition. // Cancellation is still possible. - tracePoint( kIOPMTracePointSleepStarted, sleepReason ); + tracePoint( kIOPMTracePointSleepStarted ); _systemMessageClientMask = kSystemMessageClientAll; if ((_currentCapability & kIOPMSystemCapabilityGraphics) == 0) _systemMessageClientMask &= ~kSystemMessageClientLegacyApp; if ((_highestCapability & kIOPMSystemCapabilityGraphics) == 0) _systemMessageClientMask &= ~kSystemMessageClientKernel; +#if HIBERNATION + gIOHibernateState = 0; +#endif // Record the reason for dark wake back to sleep // System may not have ever achieved full wake @@ -4985,10 +5266,20 @@ void IOPMrootDomain::handleOurPowerChangeDone( if (!CAP_CURRENT(kIOPMSystemCapabilityGraphics) && CAP_CURRENT(kIOPMSystemCapabilityCPU)) { +#if !CONFIG_EMBEDDED pmPowerStateQueue->submitPowerEvent( kPowerEventPolicyStimulus, (void *) kStimulusDarkWakeReentry, _systemStateGeneration ); +#else + // On embedded, there are no factors that can prolong a + // "darkWake" when a power down is vetoed. We need to + // promote to "fullWake" at least once so that factors + // that prevent idle sleep can assert themselves if required + pmPowerStateQueue->submitPowerEvent( + kPowerEventPolicyStimulus, + (void *) kStimulusDarkWakeActivityTickle); +#endif } // Revert device desire to max. @@ -5010,7 +5301,6 @@ void IOPMrootDomain::handleOurPowerChangeDone( { // Going dark, reset full wake state // userIsActive will be cleared by wrangler powering down - wranglerTickled = false; fullWakeReason = kFullWakeReasonNone; if (ts_sleepStart) { @@ -5102,6 +5392,9 @@ void IOPMrootDomain::handleOurPowerChangeDone( darkWakePostTickle = false; reportUserInput(); } + else if (wranglerTickled) { + requestFullWake( kFullWakeReasonLocalUser ); + } // Reset tracepoint at completion of capability change, // completion of wake transition, and aborted sleep transition. @@ -5112,7 +5405,7 @@ void IOPMrootDomain::handleOurPowerChangeDone( (changeFlags & kIOPMNotDone))) { setProperty(kIOPMSystemCapabilitiesKey, _currentCapability, 64); - tracePoint( kIOPMTracePointSystemUp, 0 ); + tracePoint( kIOPMTracePointSystemUp ); } _systemTransitionType = kSystemTransitionNone; @@ -5120,6 +5413,16 @@ void IOPMrootDomain::handleOurPowerChangeDone( toldPowerdCapWillChange = false; logGraphicsClamp = false; + + if (lowBatteryCondition) { + privateSleepSystem (kIOPMSleepReasonLowPower); + } + else if ((fullWakeReason == kFullWakeReasonDisplayOn) && (!displayPowerOnRequested)) { + // Request for full wake is removed while system is waking up to full wake + DLOG("DisplayOn fullwake request is removed\n"); + handleDisplayPowerOn(); + } + } } @@ -5256,7 +5559,7 @@ void IOPMrootDomain::overridePowerChangeForUIService( uint64_t nsec; clock_get_uptime(&now); - SUB_ABSOLUTETIME(&now, &systemWakeTime); + SUB_ABSOLUTETIME(&now, &gIOLastWakeAbsTime); absolutetime_to_nanoseconds(now, &nsec); if (kIOLogPMRootDomain & gIOKitDebug) MSG("Graphics suppressed %u ms\n", @@ -5349,6 +5652,13 @@ void IOPMrootDomain::handleUpdatePowerClientForDisplayWrangler( evaluatePolicy( kStimulusLeaveUserActiveState ); } } + + if (newPowerState <= kWranglerPowerStateSleep) { + evaluatePolicy( kStimulusDisplayWranglerSleep ); + } + else if (newPowerState == kWranglerPowerStateMax) { + evaluatePolicy( kStimulusDisplayWranglerWake ); + } #endif } @@ -5436,7 +5746,11 @@ class IOPMServiceInterestNotifier: public _IOServiceInterestNotifier protected: uint32_t ackTimeoutCnt; + uint32_t msgType; // Message pending ack + uint64_t uuid0; + uint64_t uuid1; + const OSSymbol *identifier; }; OSDefineMetaClassAndStructors(IOPMServiceInterestNotifier, _IOServiceInterestNotifier) @@ -5466,7 +5780,7 @@ IONotifier * IOPMrootDomain::registerInterest( if (!notifier) return NULL; if (notifier->init()) { - rc = super::registerInterestForNotifer(notifier, typeOfInterest, handler, target, ref); + rc = super::registerInterestForNotifier(notifier, typeOfInterest, handler, target, ref); } if (rc != kIOReturnSuccess) { notifier->release(); @@ -5494,6 +5808,28 @@ IONotifier * IOPMrootDomain::registerInterest( } } + OSData *data = NULL; + uint8_t *uuid = NULL; + OSKext *kext = OSKext::lookupKextWithAddress((vm_address_t)handler); + if (kext) { + data = kext->copyUUID(); + } + if (data && (data->getLength() == sizeof(uuid_t))) { + uuid = (uint8_t *)(data->getBytesNoCopy()); + + notifier->uuid0 = ((uint64_t)(uuid[0]) << 56) | ((uint64_t)(uuid[1]) << 48) | ((uint64_t)(uuid[2]) << 40)| + ((uint64_t)(uuid[3]) << 32) | ((uint64_t)(uuid[4]) << 24) | ((uint64_t)(uuid[5]) << 16) | + ((uint64_t)(uuid[6]) << 8) | (uuid[7]); + notifier->uuid1 = ((uint64_t)(uuid[8]) << 56) | ((uint64_t)(uuid[9]) << 48) | ((uint64_t)(uuid[10]) << 40)| + ((uint64_t)(uuid[11]) << 32) | ((uint64_t)(uuid[12]) << 24) | ((uint64_t)(uuid[13]) << 16) | + ((uint64_t)(uuid[14]) << 8) | (uuid[15]); + + notifier->identifier = kext->getIdentifier(); + + } + if (kext) kext->release(); + if (data) data->release(); + return notifier; } @@ -5509,7 +5845,9 @@ bool IOPMrootDomain::systemMessageFilter( bool isCapMsg = (context->messageType == kIOMessageSystemCapabilityChange); bool isCapClient = false; bool allow = false; + IOPMServiceInterestNotifier *notifier; + notifier = OSDynamicCast(IOPMServiceInterestNotifier, (OSObject *)object); do { if ((kSystemTransitionNewCapClient == _systemTransitionType) && (!isCapMsg || !_joinedCapabilityClients || @@ -5567,6 +5905,7 @@ bool IOPMrootDomain::systemMessageFilter( { // app has not replied yet, wait for it *((OSObject **) arg3) = kOSBooleanFalse; + } allow = true; @@ -5598,8 +5937,9 @@ bool IOPMrootDomain::systemMessageFilter( { if ((object == (OSObject *) systemCapabilityNotifier) && CAP_HIGHEST(kIOPMSystemCapabilityGraphics) && - (fullToDarkReason == kIOPMSleepReasonIdle)) + (fullToDarkReason == kIOPMSleepReasonIdle)) { allow = true; + } break; } @@ -5616,16 +5956,15 @@ bool IOPMrootDomain::systemMessageFilter( if ((context->notifyType == kNotifyApps) && (_systemMessageClientMask & kSystemMessageClientLegacyApp)) { - IOPMServiceInterestNotifier *notify; allow = true; - if ((notify = OSDynamicCast(IOPMServiceInterestNotifier, (OSObject *)object)) - && arg3) { - - if (notify->ackTimeoutCnt >= 3) - *((OSObject **) arg3) = kOSBooleanFalse; - else - *((OSObject **) arg3) = kOSBooleanTrue; + if (notifier) { + if (arg3) { + if (notifier->ackTimeoutCnt >= 3) + *((OSObject **) arg3) = kOSBooleanFalse; + else + *((OSObject **) arg3) = kOSBooleanTrue; + } } } else if ((context->notifyType == kNotifyPriority) && @@ -5647,6 +5986,9 @@ bool IOPMrootDomain::systemMessageFilter( _joinedCapabilityClients = 0; } } + if (notifier) { + notifier->msgType = context->messageType; + } return allow; } @@ -5839,7 +6181,7 @@ void IOPMrootDomain::reportUserInput( void ) if (matching) matching->release(); if(iter) { - wrangler = (IOService *) iter->getNextObject(); + wrangler = OSDynamicCast(IOService, iter->getNextObject()); iter->release(); } } @@ -6064,6 +6406,19 @@ bool IOPMrootDomain::checkSystemCanSustainFullWake( void ) return true; } +//****************************************************************************** +// mustHibernate +//****************************************************************************** + +#if HIBERNATION + +bool IOPMrootDomain::mustHibernate( void ) +{ + return (lowBatteryCondition || thermalWarningState); +} + +#endif /* HIBERNATION */ + //****************************************************************************** // adjustPowerState // @@ -6076,12 +6431,12 @@ bool IOPMrootDomain::checkSystemCanSustainFullWake( void ) void IOPMrootDomain::adjustPowerState( bool sleepASAP ) { - DLOG("adjustPowerState ps %u, asap %d, slider %ld\n", - (uint32_t) getPowerState(), sleepASAP, sleepSlider); + DLOG("adjustPowerState ps %u, asap %d, idleSleepEnabled %d\n", + (uint32_t) getPowerState(), sleepASAP, idleSleepEnabled); ASSERT_GATED(); - if ((sleepSlider == 0) || !checkSystemSleepEnabled()) + if ((!idleSleepEnabled) || !checkSystemSleepEnabled()) { changePowerStateToPriv(ON_STATE); } @@ -6135,20 +6490,22 @@ void IOPMrootDomain::handleDisplayPowerOn( ) void IOPMrootDomain::dispatchPowerEvent( uint32_t event, void * arg0, uint64_t arg1 ) { - DLOG("power event %u args %p 0x%llx\n", event, OBFUSCATE(arg0), arg1); ASSERT_GATED(); switch (event) { case kPowerEventFeatureChanged: + DMSG("power event %u args %p 0x%llx\n", event, OBFUSCATE(arg0), arg1); messageClients(kIOPMMessageFeatureChange, this); break; case kPowerEventReceivedPowerNotification: + DMSG("power event %u args %p 0x%llx\n", event, OBFUSCATE(arg0), arg1); handlePowerNotification( (UInt32)(uintptr_t) arg0 ); break; case kPowerEventSystemBootCompleted: + DLOG("power event %u args %p 0x%llx\n", event, OBFUSCATE(arg0), arg1); if (systemBooting) { systemBooting = false; @@ -6188,6 +6545,7 @@ void IOPMrootDomain::dispatchPowerEvent( break; case kPowerEventSystemShutdown: + DLOG("power event %u args %p 0x%llx\n", event, OBFUSCATE(arg0), arg1); if (kOSBooleanTrue == (OSBoolean *) arg0) { /* We set systemShutdown = true during shutdown @@ -6202,18 +6560,20 @@ void IOPMrootDomain::dispatchPowerEvent( systemShutdown = true; } else { /* - A shutdown was initiated, but then the shutdown - was cancelled, clearing systemShutdown to false here. - */ + A shutdown was initiated, but then the shutdown + was cancelled, clearing systemShutdown to false here. + */ systemShutdown = false; } break; case kPowerEventUserDisabledSleep: + DLOG("power event %u args %p 0x%llx\n", event, OBFUSCATE(arg0), arg1); userDisabledAllSleep = (kOSBooleanTrue == (OSBoolean *) arg0); break; case kPowerEventRegisterSystemCapabilityClient: + DLOG("power event %u args %p 0x%llx\n", event, OBFUSCATE(arg0), arg1); if (systemCapabilityNotifier) { systemCapabilityNotifier->release(); @@ -6225,8 +6585,10 @@ void IOPMrootDomain::dispatchPowerEvent( systemCapabilityNotifier->retain(); } /* intentional fall-through */ + [[clang::fallthrough]]; case kPowerEventRegisterKernelCapabilityClient: + DLOG("power event %u args %p 0x%llx\n", event, OBFUSCATE(arg0), arg1); if (!_joinedCapabilityClients) _joinedCapabilityClients = OSSet::withCapacity(8); if (arg0) @@ -6242,6 +6604,7 @@ void IOPMrootDomain::dispatchPowerEvent( break; case kPowerEventPolicyStimulus: + DMSG("power event %u args %p 0x%llx\n", event, OBFUSCATE(arg0), arg1); if (arg0) { int stimulus = (uintptr_t) arg0; @@ -6250,6 +6613,7 @@ void IOPMrootDomain::dispatchPowerEvent( break; case kPowerEventAssertionCreate: + DMSG("power event %u args %p 0x%llx\n", event, OBFUSCATE(arg0), arg1); if (pmAssertions) { pmAssertions->handleCreateAssertion((OSData *)arg0); } @@ -6257,25 +6621,30 @@ void IOPMrootDomain::dispatchPowerEvent( case kPowerEventAssertionRelease: + DMSG("power event %u args %p 0x%llx\n", event, OBFUSCATE(arg0), arg1); if (pmAssertions) { pmAssertions->handleReleaseAssertion(arg1); } break; case kPowerEventAssertionSetLevel: + DMSG("power event %u args %p 0x%llx\n", event, OBFUSCATE(arg0), arg1); if (pmAssertions) { pmAssertions->handleSetAssertionLevel(arg1, (IOPMDriverAssertionLevel)(uintptr_t)arg0); } break; case kPowerEventQueueSleepWakeUUID: + DLOG("power event %u args %p 0x%llx\n", event, OBFUSCATE(arg0), arg1); handleQueueSleepWakeUUID((OSObject *)arg0); break; case kPowerEventPublishSleepWakeUUID: + DLOG("power event %u args %p 0x%llx\n", event, OBFUSCATE(arg0), arg1); handlePublishSleepWakeUUID((bool)arg0); break; case kPowerEventSetDisplayPowerOn: + DLOG("power event %u args %p 0x%llx\n", event, OBFUSCATE(arg0), arg1); if (!wrangler) break; if (arg1 != 0) { @@ -6460,6 +6829,7 @@ void IOPMrootDomain::handlePowerNotification( UInt32 msg ) */ if (msg & kIOPMClamshellOpened) { + DLOG("Clamshell opened\n"); // Received clamshel open message from clamshell controlling driver // Update our internal state and tell general interest clients clamshellClosed = false; @@ -6491,6 +6861,7 @@ void IOPMrootDomain::handlePowerNotification( UInt32 msg ) */ if (msg & kIOPMClamshellClosed) { + DLOG("Clamshell closed\n"); // Received clamshel open message from clamshell controlling driver // Update our internal state and tell general interest clients clamshellClosed = true; @@ -6513,6 +6884,7 @@ void IOPMrootDomain::handlePowerNotification( UInt32 msg ) */ if (msg & kIOPMSetDesktopMode) { + DLOG("Desktop mode\n"); desktopMode = (0 != (msg & kIOPMSetValue)); msg &= ~(kIOPMSetDesktopMode | kIOPMSetValue); @@ -6566,6 +6938,7 @@ void IOPMrootDomain::handlePowerNotification( UInt32 msg ) */ if (msg & kIOPMEnableClamshell) { + DLOG("Clamshell enabled\n"); // Re-evaluate the lid state // System should sleep on external display disappearance // in lid closed operation. @@ -6585,6 +6958,7 @@ void IOPMrootDomain::handlePowerNotification( UInt32 msg ) */ if (msg & kIOPMDisableClamshell) { + DLOG("Clamshell disabled\n"); clamshellDisabled = true; sendClientClamshellNotification(); } @@ -6605,6 +6979,7 @@ void IOPMrootDomain::handlePowerNotification( UInt32 msg ) */ if (msg & kIOPMPowerButton) { + DLOG("Powerbutton press\n"); if (!wranglerAsleep) { OSString *pbs = OSString::withCString("DisablePowerButtonSleep"); @@ -6640,7 +7015,6 @@ void IOPMrootDomain::evaluatePolicy( int stimulus, uint32_t arg ) uint32_t u32; } flags; - DLOG("evaluatePolicy( %d, 0x%x )\n", stimulus, arg); ASSERT_GATED(); flags.u32 = 0; @@ -6648,20 +7022,22 @@ void IOPMrootDomain::evaluatePolicy( int stimulus, uint32_t arg ) switch (stimulus) { case kStimulusDisplayWranglerSleep: + DLOG("evaluatePolicy( %d, 0x%x )\n", stimulus, arg); if (!wranglerAsleep) { // first transition to wrangler sleep or lower - wranglerAsleep = true; flags.bit.displaySleep = true; } break; case kStimulusDisplayWranglerWake: + DLOG("evaluatePolicy( %d, 0x%x )\n", stimulus, arg); displayIdleForDemandSleep = false; wranglerAsleep = false; break; case kStimulusEnterUserActiveState: + DLOG("evaluatePolicy( %d, 0x%x )\n", stimulus, arg); if (_preventUserActive) { DLOG("user active dropped\n"); @@ -6673,9 +7049,13 @@ void IOPMrootDomain::evaluatePolicy( int stimulus, uint32_t arg ) userWasActive = true; // Stay awake after dropping demand for display power on - if (kFullWakeReasonDisplayOn == fullWakeReason) + if (kFullWakeReasonDisplayOn == fullWakeReason) { fullWakeReason = fFullWakeReasonDisplayOnAndLocalUser; + DLOG("User activity while in notification wake\n"); + changePowerStateWithOverrideTo( ON_STATE, 0); + } + kdebugTrace(kPMLogUserActiveState, 0, 1, 0); setProperty(gIOPMUserIsActiveKey, kOSBooleanTrue); messageClients(kIOPMMessageUserIsActiveChanged); } @@ -6683,12 +7063,14 @@ void IOPMrootDomain::evaluatePolicy( int stimulus, uint32_t arg ) break; case kStimulusLeaveUserActiveState: + DLOG("evaluatePolicy( %d, 0x%x )\n", stimulus, arg); if (userIsActive) { userIsActive = false; clock_get_uptime(&userBecameInactiveTime); flags.bit.userBecameInactive = true; + kdebugTrace(kPMLogUserActiveState, 0, 0, 0); setProperty(gIOPMUserIsActiveKey, kOSBooleanFalse); messageClients(kIOPMMessageUserIsActiveChanged); } @@ -6696,6 +7078,7 @@ void IOPMrootDomain::evaluatePolicy( int stimulus, uint32_t arg ) case kStimulusAggressivenessChanged: { + DMSG("evaluatePolicy( %d, 0x%x )\n", stimulus, arg); unsigned long minutesToIdleSleep = 0; unsigned long minutesToDisplayDim = 0; unsigned long minutesDelta = 0; @@ -6711,8 +7094,6 @@ void IOPMrootDomain::evaluatePolicy( int stimulus, uint32_t arg ) DLOG("idle time -> %ld secs (ena %d)\n", idleSeconds, (minutesToIdleSleep != 0)); - if (0x7fffffff == minutesToIdleSleep) - minutesToIdleSleep = idleSeconds; // How long to wait before sleeping the system once // the displays turns off is indicated by 'extraSleepDelay'. @@ -6722,11 +7103,15 @@ void IOPMrootDomain::evaluatePolicy( int stimulus, uint32_t arg ) else if ( minutesToIdleSleep == minutesToDisplayDim ) minutesDelta = 1; - if ((sleepSlider == 0) && (minutesToIdleSleep != 0)) - flags.bit.idleSleepEnabled = true; + if ((!idleSleepEnabled) && (minutesToIdleSleep != 0)) + idleSleepEnabled = flags.bit.idleSleepEnabled = true; - if ((sleepSlider != 0) && (minutesToIdleSleep == 0)) + if ((idleSleepEnabled) && (minutesToIdleSleep == 0)) { flags.bit.idleSleepDisabled = true; + idleSleepEnabled = false; + } + if (0x7fffffff == minutesToIdleSleep) + minutesToIdleSleep = idleSeconds; if (((minutesDelta != extraSleepDelay) || (userActivityTime != userActivityTime_prev)) && @@ -6746,6 +7131,7 @@ void IOPMrootDomain::evaluatePolicy( int stimulus, uint32_t arg ) } break; case kStimulusDemandSystemSleep: + DLOG("evaluatePolicy( %d, 0x%x )\n", stimulus, arg); displayIdleForDemandSleep = true; if (wrangler && wranglerIdleSettings) { @@ -6762,10 +7148,12 @@ void IOPMrootDomain::evaluatePolicy( int stimulus, uint32_t arg ) break; case kStimulusAllowSystemSleepChanged: + DLOG("evaluatePolicy( %d, 0x%x )\n", stimulus, arg); flags.bit.adjustPowerState = true; break; case kStimulusDarkWakeActivityTickle: + DLOG("evaluatePolicy( %d, 0x%x )\n", stimulus, arg); // arg == true implies real and not self generated wrangler tickle. // Update wake type on PM work loop instead of the tickle thread to // eliminate the possibility of an early tickle clobbering the wake @@ -6789,6 +7177,7 @@ void IOPMrootDomain::evaluatePolicy( int stimulus, uint32_t arg ) case kStimulusDarkWakeEntry: case kStimulusDarkWakeReentry: + DLOG("evaluatePolicy( %d, 0x%x )\n", stimulus, arg); // Any system transitions since the last dark wake transition // will invalid the stimulus. @@ -6805,6 +7194,10 @@ void IOPMrootDomain::evaluatePolicy( int stimulus, uint32_t arg ) { clock_get_uptime(&userBecameInactiveTime); flags.bit.evaluateDarkWake = true; + if (activitySinceSleep()) { + DLOG("User activity recorded while going to darkwake\n"); + reportUserInput(); + } } // Always accelerate disk spindown while in dark wake, @@ -6816,6 +7209,7 @@ void IOPMrootDomain::evaluatePolicy( int stimulus, uint32_t arg ) break; case kStimulusDarkWakeEvaluate: + DMSG("evaluatePolicy( %d, 0x%x )\n", stimulus, arg); if (systemDarkWake) { flags.bit.evaluateDarkWake = true; @@ -6823,6 +7217,7 @@ void IOPMrootDomain::evaluatePolicy( int stimulus, uint32_t arg ) break; case kStimulusNoIdleSleepPreventers: + DMSG("evaluatePolicy( %d, 0x%x )\n", stimulus, arg); flags.bit.adjustPowerState = true; break; @@ -6884,6 +7279,7 @@ void IOPMrootDomain::evaluatePolicy( int stimulus, uint32_t arg ) (kFullWakeReasonDisplayOn == fullWakeReason)) { // kIOPMSleepReasonMaintenance? + DLOG("Display sleep while in notification wake\n"); changePowerStateWithOverrideTo( SLEEP_STATE, kIOPMSleepReasonMaintenance ); } @@ -6906,7 +7302,7 @@ void IOPMrootDomain::evaluatePolicy( int stimulus, uint32_t arg ) DLOG("user inactive\n"); } - if (!userIsActive && sleepSlider) + if (!userIsActive && idleSleepEnabled) { startIdleSleepTimer(getTimeToIdleSleep()); } @@ -6921,10 +7317,7 @@ void IOPMrootDomain::evaluatePolicy( int stimulus, uint32_t arg ) if (!wrangler) { changePowerStateToPriv(ON_STATE); - if (idleSeconds) - { - startIdleSleepTimer( idleSeconds ); - } + startIdleSleepTimer( idleSeconds ); } else { @@ -6956,7 +7349,7 @@ void IOPMrootDomain::evaluatePolicy( int stimulus, uint32_t arg ) if (!wrangler) { changePowerStateToPriv(ON_STATE); - if (idleSeconds) + if (idleSleepEnabled) { // stay awake for at least idleSeconds startIdleSleepTimer(idleSeconds); @@ -7048,7 +7441,7 @@ void IOPMrootDomain::requestFullWake( FullWakeReason reason ) uint64_t nsec; clock_get_uptime(&now); - SUB_ABSOLUTETIME(&now, &systemWakeTime); + SUB_ABSOLUTETIME(&now, &gIOLastWakeAbsTime); absolutetime_to_nanoseconds(now, &nsec); MSG("full wake %s (reason %u) %u ms\n", promotion ? "promotion" : "request", @@ -7070,6 +7463,8 @@ void IOPMrootDomain::willEnterFullWake( void ) { hibernateRetry = false; sleepToStandby = false; + standbyNixed = false; + resetTimers = false; sleepTimerMaintenance = false; _systemMessageClientMask = kSystemMessageClientPowerd | @@ -7134,11 +7529,11 @@ void IOPMrootDomain::evaluateAssertions(IOPMDriverAssertionType newAssertions, I if (changedBits & kIOPMDriverAssertionCPUBit) { evaluatePolicy(kStimulusDarkWakeEvaluate); - if (!assertOnWakeSecs && systemWakeTime) { + if (!assertOnWakeSecs && gIOLastWakeAbsTime) { AbsoluteTime now; clock_usec_t microsecs; clock_get_uptime(&now); - SUB_ABSOLUTETIME(&now, &systemWakeTime); + SUB_ABSOLUTETIME(&now, &gIOLastWakeAbsTime); absolutetime_to_microtime(now, &assertOnWakeSecs, µsecs); if (assertOnWakeReport) { HISTREPORT_TALLYVALUE(assertOnWakeReport, (int64_t)assertOnWakeSecs); @@ -7222,7 +7617,7 @@ void IOPMrootDomain::pmStatsRecordApplicationResponse( const char *name, int messageType, uint32_t delay_ms, - int app_pid, + uint64_t id, OSObject *object, IOPMPowerStateIndex powerState) { @@ -7237,18 +7632,32 @@ void IOPMrootDomain::pmStatsRecordApplicationResponse( if (object && (notify = OSDynamicCast(IOPMServiceInterestNotifier, object))) { - if (response->isEqualTo(gIOPMStatsApplicationResponseTimedOut)) + if (response->isEqualTo(gIOPMStatsResponseTimedOut)) notify->ackTimeoutCnt++; else notify->ackTimeoutCnt = 0; } - if (response->isEqualTo(gIOPMStatsApplicationResponsePrompt) || + if (response->isEqualTo(gIOPMStatsResponsePrompt) || (_systemTransitionType == kSystemTransitionNone) || (_systemTransitionType == kSystemTransitionNewCapClient)) return; + if (response->isEqualTo(gIOPMStatsDriverPSChangeSlow)) { + kdebugTrace(kPMLogDrvPSChangeDelay, id, messageType, delay_ms); + } + else if (notify) { + // User space app or kernel capability client + if (id) { + kdebugTrace(kPMLogAppResponseDelay, id, notify->msgType, delay_ms); + } + else { + kdebugTrace(kPMLogDrvResponseDelay, notify->uuid0, messageType, delay_ms); + } + notify->msgType = 0; + } + responseDescription = OSDictionary::withCapacity(5); if (responseDescription) { @@ -7262,6 +7671,10 @@ void IOPMrootDomain::pmStatsRecordApplicationResponse( msgNum->release(); } + if (!name && notify && notify->identifier) { + name = notify->identifier->getCStringNoCopy(); + } + if (name && (strlen(name) > 0)) { appname = OSSymbol::withCString(name); @@ -7271,8 +7684,11 @@ void IOPMrootDomain::pmStatsRecordApplicationResponse( } } - if (app_pid != -1) { - pidNum = OSNumber::withNumber(app_pid, 32); + if (!id && notify) { + id = notify->uuid0; + } + if (id != 0) { + pidNum = OSNumber::withNumber(id, 64); if (pidNum) { responseDescription->setObject(_statsPIDKey, pidNum); pidNum->release(); @@ -7351,6 +7767,8 @@ IOReturn IOPMrootDomain::callPlatformFunction( void * param1, void * param2, void * param3, void * param4 ) { + uint32_t bootFailureCode = 0xffffffff; + unsigned int len = sizeof(bootFailureCode); if (pmTracer && functionName && functionName->isEqualTo(kIOPMRegisterNVRAMTracePointHandlerKey) && !pmTracer->tracePointHandler && !pmTracer->tracePointTarget) @@ -7362,9 +7780,15 @@ IOReturn IOPMrootDomain::callPlatformFunction( pmTracer->tracePointTarget = (void *) param2; tracePointPCI = (uint32_t)(uintptr_t) param3; tracePointPhases = (uint32_t)(uintptr_t) param4; + if ((tracePointPhases & 0xff) == kIOPMTracePointSystemSleep) { + if (!PEReadNVRAMProperty(kIOEFIBootRomFailureKey, &bootFailureCode, &len)) { + MSG("Failed to read failure code from NVRam\n"); + } + // Failure code from EFI/BootRom is a four byte structure + tracePointPCI = OSSwapBigToHostInt32(bootFailureCode); + } statusCode = (((uint64_t)tracePointPCI) << 32) | tracePointPhases; - if ((tracePointPhases >> 24) != kIOPMTracePointSystemUp) - { + if ((tracePointPhases & 0xff) != kIOPMTracePointSystemUp) { MSG("Sleep failure code 0x%08x 0x%08x\n", tracePointPCI, tracePointPhases); } @@ -7392,6 +7816,18 @@ IOReturn IOPMrootDomain::callPlatformFunction( functionName, waitForFunction, param1, param2, param3, param4); } +void IOPMrootDomain::kdebugTrace(uint32_t event, uint64_t id, + uintptr_t param1, uintptr_t param2, uintptr_t param3) +{ + uint32_t code = IODBG_POWER(event); + uint64_t regId = id; + if (regId == 0) { + regId = getRegistryEntryID(); + } + IOTimeStampConstant(code, (uintptr_t) regId, param1, param2, param3); +} + + void IOPMrootDomain::tracePoint( uint8_t point ) { if (systemBooting) return; @@ -7399,22 +7835,62 @@ void IOPMrootDomain::tracePoint( uint8_t point ) if (kIOPMTracePointWakeCapabilityClients == point) acceptSystemWakeEvents(false); - PMDebug(kPMLogSleepWakeTracePoint, point, 0); + kdebugTrace(kPMLogSleepWakeTracePoint, 0, point, 0); pmTracer->tracePoint(point); } -void IOPMrootDomain::tracePoint( uint8_t point, uint8_t data ) +void IOPMrootDomain::traceDetail(OSObject *object) { - if (systemBooting) return; + IOPMServiceInterestNotifier *notifier = OSDynamicCast(IOPMServiceInterestNotifier, object); + if (!notifier) { + DLOG("Unknown notifier\n"); + return; + } + + if (!systemBooting) { + pmTracer->traceDetail( notifier->uuid0 >> 32 ); + kdebugTrace(kPMLogSleepWakeMessage, pmTracer->getTracePhase(), notifier->msgType, notifier->uuid0, notifier->uuid1); + if (notifier->identifier) { + DLOG("trace point 0x%02x msg 0x%x to %s\n", pmTracer->getTracePhase(), notifier->msgType, + notifier->identifier->getCStringNoCopy()); + } + else { + DLOG("trace point 0x%02x msg 0x%x\n", pmTracer->getTracePhase(), notifier->msgType); + } + } + +} + + +void IOPMrootDomain::traceAckDelay(OSObject *object, uint32_t response, uint32_t delay_ms) +{ + IOPMServiceInterestNotifier *notifier = OSDynamicCast(IOPMServiceInterestNotifier, object); + if (!notifier) { + DLOG("Unknown notifier\n"); + return; + } - PMDebug(kPMLogSleepWakeTracePoint, point, data); - pmTracer->tracePoint(point, data); + if (!systemBooting) { + kdebugTrace(kPMLogDrvResponseDelay, notifier->uuid0, notifier->uuid1, response, delay_ms); + if (notifier->identifier) { + DLOG("Response from %s took %d ms(response:%d)\n", + notifier->identifier->getCStringNoCopy(), delay_ms, response); + } + else { + DLOG("Response from kext UUID %llx-%llx took %d ms(response:%d)\n", + notifier->uuid0, notifier->uuid1, delay_ms, response); + } + } } -void IOPMrootDomain::traceDetail( uint32_t detail ) +void IOPMrootDomain::traceDetail(uint32_t msgType, uint32_t msgIndex, uint32_t delay) { - if (!systemBooting) + if (!systemBooting) { + uint32_t detail = ((msgType & 0xffff) << 16) | (delay & 0xffff); pmTracer->traceDetail( detail ); + kdebugTrace(kPMLogSleepWakeTracePoint, pmTracer->getTracePhase(), msgType, delay); + DLOG("trace point 0x%02x msgType 0x%x detail 0x%08x\n", pmTracer->getTracePhase(), msgType, delay); + } } @@ -7627,10 +8103,12 @@ PMTraceWorker *PMTraceWorker::tracer(IOPMrootDomain *owner) // this dictionary lazily. me->owner = owner; me->pciDeviceBitMappings = NULL; - me->pciMappingLock = IOLockAlloc(); + me->pmTraceWorkerLock = IOLockAlloc(); me->tracePhase = kIOPMTracePointSystemUp; - me->loginWindowPhase = 0; me->traceData32 = 0; + me->loginWindowData = 0; + me->coreDisplayData = 0; + me->coreGraphicsData = 0; return me; } @@ -7640,8 +8118,10 @@ void PMTraceWorker::RTC_TRACE(void) { uint32_t wordA; - wordA = (tracePhase << 24) | (loginWindowPhase << 16) | - (traceData8 << 8); + IOLockLock(pmTraceWorkerLock); + wordA = (loginWindowData << 24) | (coreDisplayData << 16) | + (coreGraphicsData << 8) | tracePhase; + IOLockUnlock(pmTraceWorkerLock); tracePointHandler( tracePointTarget, traceData32, wordA ); _LOG("RTC_TRACE wrote 0x%08x 0x%08x\n", traceData32, wordA); @@ -7653,7 +8133,7 @@ int PMTraceWorker::recordTopLevelPCIDevice(IOService * pciDevice) const OSSymbol * deviceName; int index = -1; - IOLockLock(pciMappingLock); + IOLockLock(pmTraceWorkerLock); if (!pciDeviceBitMappings) { @@ -7680,7 +8160,7 @@ int PMTraceWorker::recordTopLevelPCIDevice(IOService * pciDevice) addedToRegistry = owner->setProperty("PCITopLevel", this); exit: - IOLockUnlock(pciMappingLock); + IOLockUnlock(pmTraceWorkerLock); return index; } @@ -7689,9 +8169,9 @@ bool PMTraceWorker::serialize(OSSerialize *s) const bool ok = false; if (pciDeviceBitMappings) { - IOLockLock(pciMappingLock); + IOLockLock(pmTraceWorkerLock); ok = pciDeviceBitMappings->serialize(s); - IOLockUnlock(pciMappingLock); + IOLockUnlock(pmTraceWorkerLock); } return ok; } @@ -7708,35 +8188,32 @@ void PMTraceWorker::tracePoint(uint8_t phase) RTC_TRACE(); } -void PMTraceWorker::tracePoint(uint8_t phase, uint8_t data8) -{ - // clear trace detail when phase begins - if (tracePhase != phase) - traceData32 = 0; - - tracePhase = phase; - traceData8 = data8; - - DLOG("trace point 0x%02x 0x%02x\n", tracePhase, traceData8); - RTC_TRACE(); -} - void PMTraceWorker::traceDetail(uint32_t detail) { - if (kIOPMTracePointSleepPriorityClients != tracePhase) + if (detail == traceData32) { return; - + } traceData32 = detail; - DLOG("trace point 0x%02x detail 0x%08x\n", tracePhase, traceData32); - RTC_TRACE(); } -void PMTraceWorker::traceLoginWindowPhase(uint8_t phase) +void PMTraceWorker::traceComponentWakeProgress(uint32_t component, uint32_t data) { - loginWindowPhase = phase; - - DLOG("loginwindow tracepoint 0x%02x\n", loginWindowPhase); + switch (component) { + case kIOPMLoginWindowProgress: + loginWindowData = data & kIOPMLoginWindowProgressMask; + break; + case kIOPMCoreDisplayProgress: + coreDisplayData = data & kIOPMCoreDisplayProgressMask; + break; + case kIOPMCoreGraphicsProgress: + coreGraphicsData = data & kIOPMCoreGraphicsProgressMask; + break; + default: + return; + } + + DLOG("component trace point 0x%02x data 0x%08x\n", component, data); RTC_TRACE(); } @@ -7769,12 +8246,14 @@ void PMTraceWorker::tracePCIPowerChange( traceData32 |= bitMask; _LOG("PMTrace: Device %s started - bit %2d mask 0x%08x => 0x%08x\n", service->getName(), bitNum, bitMask, traceData32); + owner->kdebugTrace(kPMLogPCIDevChangeStart, service->getRegistryEntryID(), traceData32, 0); } else { traceData32 &= ~bitMask; _LOG("PMTrace: Device %s finished - bit %2d mask 0x%08x => 0x%08x\n", service->getName(), bitNum, bitMask, traceData32); + owner->kdebugTrace(kPMLogPCIDevChangeDone, service->getRegistryEntryID(), traceData32, 0); } DLOG("trace point 0x%02x detail 0x%08x\n", tracePhase, traceData32); @@ -7784,9 +8263,18 @@ void PMTraceWorker::tracePCIPowerChange( uint64_t PMTraceWorker::getPMStatusCode( ) { - return (((uint64_t)traceData32 << 32) | ((uint64_t)tracePhase << 24) | - (loginWindowPhase << 16) | (traceData8 << 8)); + return (((uint64_t)traceData32 << 32) | ((uint64_t)tracePhase)); + +} + +uint8_t PMTraceWorker::getTracePhase() +{ + return tracePhase; +} +uint32_t PMTraceWorker::getTraceData() +{ + return traceData32; } // MARK: - @@ -7883,7 +8371,7 @@ void PMHaltWorker::work( PMHaltWorker * me ) { IOService * service; OSSet * inner; - AbsoluteTime startTime; + AbsoluteTime startTime, elapsedTime; UInt32 deltaTime; bool timeout; @@ -7897,7 +8385,7 @@ void PMHaltWorker::work( PMHaltWorker * me ) inner = (OSSet *)gPMHaltArray->getObject(me->depth); if (inner) { - service = (IOService *)inner->getAnyObject(); + service = OSDynamicCast(IOService, inner->getAnyObject()); if (service) { service->retain(); @@ -7932,7 +8420,7 @@ void PMHaltWorker::work( PMHaltWorker * me ) IOLockUnlock(me->lock); } - deltaTime = computeDeltaTimeMS(&startTime); + deltaTime = computeDeltaTimeMS(&startTime, &elapsedTime); if ((deltaTime > kPMHaltTimeoutMS) || timeout || (gIOKitDebug & kIOLogPMRootDomain)) { @@ -7941,6 +8429,10 @@ void PMHaltWorker::work( PMHaltWorker * me ) "PowerOff" : "Restart", service->getName(), service->getRegistryEntryID(), (uint32_t) deltaTime ); + halt_log_enter( + (gPMHaltMessageType == kIOMessageSystemWillPowerOff) ? "PowerOff" : "Restart", + OSMemberFunctionCast(const void *, service, &IOService::systemWillShutdown), + elapsedTime); } service->release(); @@ -8413,6 +8905,29 @@ void IOPMrootDomain::acceptSystemWakeEvents( bool accept ) else { _acceptSystemWakeEvents = false; +#if CONFIG_EMBEDDED + logWakeReason = gWakeReasonSysctlRegistered; +#if DEVELOPMENT + static int panic_allowed = -1; + + if ((panic_allowed == -1) && + (PE_parse_boot_argn("swd_wakereason_panic", &panic_allowed, sizeof(panic_allowed)) == false)) { + panic_allowed = 1; + } + + if (panic_allowed) { + size_t i = 0; + // Panic if wake reason is null or empty + for (i = 0; (i < strlen(gWakeReasonString)); i++) { + if ((gWakeReasonString[i] != ' ') && (gWakeReasonString[i] != '\t')) + break; + } + if (i >= strlen(gWakeReasonString)) { + panic("Wake reason is empty\n"); + } + } +#endif +#endif } WAKEEVENT_UNLOCK(); @@ -8468,6 +8983,9 @@ void IOPMrootDomain::claimSystemWakeEvent( // Lazy registration until the platform driver stops registering // the same name. gWakeReasonSysctlRegistered = true; +#if CONFIG_EMBEDDED + sysctl_register_oid(&sysctl__kern_wakereason); +#endif } if (_acceptSystemWakeEvents) { @@ -9116,20 +9634,23 @@ void IOPMrootDomain::takeStackshot(bool wdogTrigger, bool isOSXWatchdog, bool is { swd_hdr * hdr = NULL; addr64_t data[3]; - uint32_t wdog_panic = 0; + int wdog_panic = -1; + int stress_rack = -1; int cnt = 0; pid_t pid = 0; + kern_return_t kr = KERN_SUCCESS; uint32_t flags; char * dstAddr; uint32_t size; uint32_t bytesRemaining; + unsigned bytesWritten = 0; + unsigned totalBytes = 0; unsigned int len; OSString * UUIDstring = NULL; uint64_t code; IOMemoryMap * logBufMap = NULL; - swd_stackshot_hdr *stackshotHdr = NULL; uint32_t bufSize; uint32_t initialStackSize; @@ -9144,10 +9665,11 @@ void IOPMrootDomain::takeStackshot(bool wdogTrigger, bool isOSXWatchdog, bool is } if (wdogTrigger) { - if (PE_parse_boot_argn("swd_panic", &wdog_panic, sizeof(wdog_panic)) && - (wdog_panic == 1)) { - // If boot-arg is set to panic on sleep/wake hang, call panic - panic("Sleep/Wake hang detected\n"); + PE_parse_boot_argn("swd_panic", &wdog_panic, sizeof(wdog_panic)); + PE_parse_boot_argn("stress-rack", &stress_rack, sizeof(stress_rack)); + if ((wdog_panic == 1) || (stress_rack == 1)) { + // If boot-arg specifies to panic then panic. + panic("Sleep/Wake hang detected"); return; } else if (swd_flags & SWD_BOOT_BY_SW_WDOG) { @@ -9155,6 +9677,10 @@ void IOPMrootDomain::takeStackshot(bool wdogTrigger, bool isOSXWatchdog, bool is // then don't trigger again until at least 1 successful sleep & wake. if (!(sleepCnt && (displayWakeCnt || darkWakeCnt))) { IOLog("Shutting down due to repeated Sleep/Wake failures\n"); + if (!tasksSuspended) { + tasksSuspended = TRUE; + tasks_system_suspend(true); + } PEHaltRestart(kPEHaltCPU); return; } @@ -9188,10 +9714,13 @@ void IOPMrootDomain::takeStackshot(bool wdogTrigger, bool isOSXWatchdog, bool is if (!OSCompareAndSwap(0, 1, &gRootDomain->swd_lock)) return; - if (isSpinDump) + if (isSpinDump) { hdr = (swd_hdr *)swd_spindump_buffer; - else + } + else { hdr = (swd_hdr *)swd_buffer; + } + memset(hdr->UUID, 0x20, sizeof(hdr->UUID)); if ((UUIDstring = OSDynamicCast(OSString, getProperty(kIOPMSleepWakeUUIDKey))) != NULL ) { @@ -9213,51 +9742,54 @@ void IOPMrootDomain::takeStackshot(bool wdogTrigger, bool isOSXWatchdog, bool is DLOG("Taking snapshot. bytesRemaining: %d\n", bytesRemaining); - while (bytesRemaining > sizeof(swd_stackshot_hdr)) { + flags = STACKSHOT_KCDATA_FORMAT|STACKSHOT_NO_IO_STATS|STACKSHOT_SAVE_KEXT_LOADINFO; + while (kr == KERN_SUCCESS) { - stackshotHdr = (swd_stackshot_hdr *)dstAddr; - stackshotHdr->magic = SWD_STACKSHOTHDR_MAGIC; - stackshotHdr->size = 0; - bytesRemaining -= sizeof(swd_stackshot_hdr); - dstAddr += sizeof(swd_stackshot_hdr); - - if (isOSXWatchdog) { - pid = -1; - size = bytesRemaining; - flags = STACKSHOT_SAVE_LOADINFO | STACKSHOT_SAVE_KEXT_LOADINFO; - } - else if (cnt == 0) { - /* + if (cnt == 0) { + /* * Take stackshot of all process on first sample. Size is restricted * to SWD_INITIAL_STACK_SIZE */ pid = -1; size = (bytesRemaining > initialStackSize) ? initialStackSize : bytesRemaining; - flags = STACKSHOT_SAVE_LOADINFO | STACKSHOT_SAVE_KEXT_LOADINFO|STACKSHOT_SAVE_KERNEL_FRAMES_ONLY; + flags |= STACKSHOT_ACTIVE_KERNEL_THREADS_ONLY; } else { /* Take sample of kernel threads only */ pid = 0; size = bytesRemaining; - flags = 0; } - stack_snapshot_from_kernel(pid, dstAddr, size, flags, &stackshotHdr->size); + kr = stack_snapshot_from_kernel(pid, dstAddr, size, flags, 0, &bytesWritten); + DLOG("stack_snapshot_from_kernel returned 0x%x. pid: %d bufsize:0x%x flags:0x%x bytesWritten: %d\n", + kr, pid, size, flags, bytesWritten); + if (kr == KERN_INSUFFICIENT_BUFFER_SIZE) { + if (pid == -1) { + // Insufficient buffer when trying to take stackshot of user & kernel space threads. + // Continue to take stackshot of just kernel threads + ++cnt; + kr = KERN_SUCCESS; + continue; + } + else if (totalBytes == 0) { + MSG("Failed to get stackshot(0x%x) bufsize:0x%x flags:0x%x\n", kr, size, flags); + } + } - dstAddr += stackshotHdr->size; - bytesRemaining -= stackshotHdr->size; + dstAddr += bytesWritten; + totalBytes += bytesWritten; + bytesRemaining -= bytesWritten; - DLOG("Sample: %d size: %d bytesRemaining: %d\n", cnt, stackshotHdr->size, bytesRemaining); - if ((stackshotHdr->size == 0) || (++cnt == 10)) + if (++cnt == 10) { break; + } IOSleep(10); // 10 ms } hdr->spindump_size = (bufSize - bytesRemaining - hdr->spindump_offset); - memset(hdr->cps, 0x20, sizeof(hdr->cps)); - snprintf(hdr->cps, sizeof(hdr->cps), "\ncps: %d", ((IOService*)this)->getPowerState()); + memset(hdr->spindump_status, 0x20, sizeof(hdr->spindump_status)); code = pmTracer->getPMStatusCode(); memset(hdr->PMStatusCode, 0x20, sizeof(hdr->PMStatusCode)); snprintf(hdr->PMStatusCode, sizeof(hdr->PMStatusCode), "\nCode: %08x %08x", @@ -9291,8 +9823,13 @@ exit: gRootDomain->swd_lock = 0; if (wdogTrigger) { - IOLog("Restarting to collect Sleep wake debug logs\n"); - PEHaltRestart(kPERestartCPU); + IOLog("Restarting to collect Sleep wake debug logs\n"); + if (!tasksSuspended) { + tasksSuspended = TRUE; + tasks_system_suspend(true); + } + + PEHaltRestart(kPERestartCPU); } else { logBufMap = sleepWakeDebugRetrieve(); @@ -9344,6 +9881,7 @@ void IOPMrootDomain::sleepWakeDebugMemAlloc( ) hdr->spindump_offset = sizeof(swd_hdr); swd_buffer = (void *)hdr; + swd_memDesc = memDesc; DLOG("SleepWake debug buffer size:0x%x spindump offset:0x%x\n", hdr->alloc_size, hdr->spindump_offset); exit: @@ -9431,6 +9969,7 @@ errno_t IOPMrootDomain::sleepWakeDebugSaveFile(const char *name, char *buf, int S_IRUSR|S_IRGRP|S_IROTH, VNODE_LOOKUP_NOFOLLOW, &vp, ctx) != 0) { IOLog("Failed to open the file %s\n", name); + swd_flags |= SWD_FILEOP_ERROR; goto exit; } VATTR_INIT(&va); @@ -9439,6 +9978,7 @@ errno_t IOPMrootDomain::sleepWakeDebugSaveFile(const char *name, char *buf, int if (vp->v_type != VREG || vnode_getattr(vp, &va, ctx) || va.va_nlink != 1) { IOLog("Bailing as this is not a regular file\n"); + swd_flags |= SWD_FILEOP_ERROR; goto exit; } VATTR_INIT(&va); @@ -9446,12 +9986,17 @@ errno_t IOPMrootDomain::sleepWakeDebugSaveFile(const char *name, char *buf, int vnode_setattr(vp, &va, ctx); - error = vn_rdwr(UIO_WRITE, vp, buf, len, 0, - UIO_SYSSPACE, IO_NODELOCKED|IO_UNIT, cred, (int *) 0, vfs_context_proc(ctx)); - if (error != 0) - IOLog("Failed to save sleep wake log. err 0x%x\n", error); - else - DLOG("Saved %d bytes to file %s\n",len, name); + if (buf != NULL) { + error = vn_rdwr(UIO_WRITE, vp, buf, len, 0, + UIO_SYSSPACE, IO_NODELOCKED|IO_UNIT, cred, (int *) 0, vfs_context_proc(ctx)); + if (error != 0) { + IOLog("Failed to save sleep wake log. err 0x%x\n", error); + swd_flags |= SWD_FILEOP_ERROR; + } + else { + DLOG("Saved %d bytes to file %s\n",len, name); + } + } exit: if (vp) vnode_close(vp, FWRITE, ctx); @@ -9481,7 +10026,8 @@ errno_t IOPMrootDomain::sleepWakeDebugCopyFile( if (vnode_open(dstFname, (O_CREAT | FWRITE | O_NOFOLLOW), S_IRUSR|S_IRGRP|S_IROTH, VNODE_LOOKUP_NOFOLLOW, &vp, ctx) != 0) { - DLOG("Failed to open the file %s\n", dstFname); + IOLog("Failed to open the file %s\n", dstFname); + swd_flags |= SWD_FILEOP_ERROR; goto exit; } VATTR_INIT(&va); @@ -9489,7 +10035,8 @@ errno_t IOPMrootDomain::sleepWakeDebugCopyFile( /* Don't dump to non-regular files or files with links. */ if (vp->v_type != VREG || vnode_getattr(vp, &va, ctx) || va.va_nlink != 1) { - DLOG("Bailing as this is not a regular file\n"); + IOLog("Bailing as this is not a regular file\n"); + swd_flags |= SWD_FILEOP_ERROR; goto exit; } VATTR_INIT(&va); @@ -9507,7 +10054,8 @@ errno_t IOPMrootDomain::sleepWakeDebugCopyFile( vfs_context_ucred(srcCtx), (int *) 0, vfs_context_proc(srcCtx)); if (error) { - DLOG("Failed to read file(numBytes:0x%llx)\n", bytesToRead); + IOLog("Failed to read file(numBytes:0x%llx)\n", bytesToRead); + swd_flags |= SWD_FILEOP_ERROR; break; } @@ -9524,7 +10072,8 @@ errno_t IOPMrootDomain::sleepWakeDebugCopyFile( vfs_context_ucred(ctx), (int *) 0, vfs_context_proc(ctx)); if (error) { - DLOG("Failed to write file(numBytes:0x%llx)\n", bytesToWrite); + IOLog("Failed to write file(numBytes:0x%llx)\n", bytesToWrite); + swd_flags |= SWD_FILEOP_ERROR; break; } @@ -9534,26 +10083,19 @@ errno_t IOPMrootDomain::sleepWakeDebugCopyFile( } if (crc != newcrc) { - swd_stackshot_hdr *shdr = (swd_stackshot_hdr *)tmpBuf;; - - /* Set statckshot size to 0 if crc doesn't match */ - shdr->magic = SWD_STACKSHOTHDR_MAGIC; - shdr->size = 0; - - assert(tmpBufSize > sizeof(swd_stackshot_hdr)); - bytesToWrite = round_page(sizeof(swd_stackshot_hdr)); - vn_rdwr(UIO_WRITE, vp, (char *)tmpBuf, bytesToWrite, 0, - UIO_SYSSPACE, IO_SYNC|IO_NODELOCKED|IO_UNIT, - vfs_context_ucred(ctx), (int *) 0, - vfs_context_proc(ctx)); + /* Set stackshot size to 0 if crc doesn't match */ + VATTR_INIT(&va); + VATTR_SET(&va, va_data_size, 0); + vnode_setattr(vp, &va, ctx); - DLOG("CRC check failed. expected:0x%x actual:0x%x\n", crc, newcrc); + IOLog("CRC check failed. expected:0x%x actual:0x%x\n", crc, newcrc); + swd_flags |= SWD_DATA_CRC_ERROR; error = EFAULT; } exit: if (vp) { error = vnode_close(vp, FWRITE, ctx); - DLOG("vnode_close returned 0x%x\n", error); + DLOG("vnode_close on file %s returned 0x%x\n",dstFname, error); } if (ctx) vfs_context_rele(ctx); @@ -9562,11 +10104,12 @@ exit: } -void IOPMrootDomain::checkForValidDebugData(const char *fname, vfs_context_t *ctx, +uint32_t IOPMrootDomain::checkForValidDebugData(const char *fname, vfs_context_t *ctx, void *tmpBuf, struct vnode **vp) { int rc; uint64_t hdrOffset; + uint32_t error = 0; struct vnode_attr va; IOHibernateImageHeader *imageHdr; @@ -9583,7 +10126,8 @@ void IOPMrootDomain::checkForValidDebugData(const char *fname, vfs_context_t *ct VATTR_WANTED(&va, va_data_alloc); if ((*vp)->v_type != VREG || vnode_getattr((*vp), &va, *ctx) || va.va_nlink != 1) { - DMSG("sleepWakeDebugDumpFromFile: Bailing as %s is not a regular file\n", fname); + IOLog("sleepWakeDebugDumpFromFile: Bailing as %s is not a regular file\n", fname); + error = SWD_FILEOP_ERROR; goto err; } @@ -9593,33 +10137,36 @@ void IOPMrootDomain::checkForValidDebugData(const char *fname, vfs_context_t *ct vfs_context_ucred(*ctx), (int *) 0, vfs_context_proc(*ctx)); if (rc != 0) { - DMSG("sleepWakeDebugDumpFromFile: Failed to read header size %lu(rc=%d) from %s\n", - round_page(sizeof(IOHibernateImageHeader)), rc, fname); + IOLog("sleepWakeDebugDumpFromFile: Failed to read header size %llu(rc=%d) from %s\n", + mach_vm_round_page(sizeof(IOHibernateImageHeader)), rc, fname); + error = SWD_FILEOP_ERROR; goto err; } imageHdr = ((IOHibernateImageHeader *)tmpBuf); if (imageHdr->signature != kIOHibernateHeaderDebugDataSignature) { - DMSG("sleepWakeDebugDumpFromFile: File %s header has unexpected value 0x%x\n", + IOLog("sleepWakeDebugDumpFromFile: File %s header has unexpected value 0x%x\n", fname, imageHdr->signature); + error = SWD_HDR_SIGNATURE_ERROR; goto err; } /* Sleep/Wake debug header(swd_hdr) is at the beggining of the second block */ hdrOffset = imageHdr->deviceBlockSize; if (hdrOffset + sizeof(swd_hdr) >= va.va_data_alloc) { - DMSG("sleepWakeDebugDumpFromFile: header is crossing file size(0x%llx) in file %s\n", + IOLog("sleepWakeDebugDumpFromFile: header is crossing file size(0x%llx) in file %s\n", va.va_data_alloc, fname); + error = SWD_HDR_SIZE_ERROR; goto err; } - return; + return 0; err: if (*vp) vnode_close(*vp, FREAD, *ctx); *vp = NULL; - return; + return error; } void IOPMrootDomain::sleepWakeDebugDumpFromFile( ) @@ -9627,7 +10174,6 @@ void IOPMrootDomain::sleepWakeDebugDumpFromFile( ) #if HIBERNATION int rc; char hibernateFilename[MAXPATHLEN+1]; - char PMStatusCode[100]; void *tmpBuf; swd_hdr *hdr = NULL; uint32_t stacksSize, logSize; @@ -9639,6 +10185,7 @@ void IOPMrootDomain::sleepWakeDebugDumpFromFile( ) OSNumber *failStat = NULL; struct vnode *vp = NULL; vfs_context_t ctx = NULL; + const char *stacksFname, *logFname; IOBufferMemoryDescriptor *tmpBufDesc = NULL; @@ -9666,7 +10213,7 @@ void IOPMrootDomain::sleepWakeDebugDumpFromFile( ) ctx = vfs_context_create(vfs_context_current()); /* First check if 'kSleepWakeStackBinFilename' has valid data */ - checkForValidDebugData(kSleepWakeStackBinFilename, &ctx, tmpBuf, &vp); + swd_flags |= checkForValidDebugData(kSleepWakeStackBinFilename, &ctx, tmpBuf, &vp); if (vp == NULL) { /* Check if the debug data is saved to hibernation file */ hibernateFilename[0] = 0; @@ -9682,7 +10229,7 @@ void IOPMrootDomain::sleepWakeDebugDumpFromFile( ) goto exit; } - checkForValidDebugData(hibernateFilename, &ctx, tmpBuf, &vp); + swd_flags |= checkForValidDebugData(hibernateFilename, &ctx, tmpBuf, &vp); if (vp == NULL) { DMSG("sleepWakeDebugDumpFromFile: No valid debug data is found\n"); goto exit; @@ -9695,15 +10242,16 @@ void IOPMrootDomain::sleepWakeDebugDumpFromFile( ) hdrOffset = ((IOHibernateImageHeader *)tmpBuf)->deviceBlockSize; - DLOG("Reading swd_hdr len 0x%lx offset 0x%lx\n", round_page(sizeof(swd_hdr)), trunc_page(hdrOffset)); + DLOG("Reading swd_hdr len 0x%llx offset 0x%lx\n", mach_vm_round_page(sizeof(swd_hdr)), trunc_page(hdrOffset)); /* Read the sleep/wake debug header(swd_hdr) */ rc = vn_rdwr(UIO_READ, vp, (char *)tmpBuf, round_page(sizeof(swd_hdr)), trunc_page(hdrOffset), UIO_SYSSPACE, IO_SKIP_ENCRYPTION|IO_SYNC|IO_NODELOCKED|IO_UNIT|IO_NOCACHE, vfs_context_ucred(ctx), (int *) 0, vfs_context_proc(ctx)); if (rc != 0) { - DMSG("sleepWakeDebugDumpFromFile: Failed to debug read header size %lu. rc=%d\n", - round_page(sizeof(swd_hdr)), rc); + DMSG("sleepWakeDebugDumpFromFile: Failed to debug read header size %llu. rc=%d\n", + mach_vm_round_page(sizeof(swd_hdr)), rc); + swd_flags |= SWD_FILEOP_ERROR; goto exit; } @@ -9712,6 +10260,7 @@ void IOPMrootDomain::sleepWakeDebugDumpFromFile( ) (hdr->spindump_offset > SWD_BUF_SIZE) || (hdr->spindump_size > SWD_BUF_SIZE)) { DMSG("sleepWakeDebugDumpFromFile: Invalid data in debug header. sign:0x%x size:0x%x spindump_offset:0x%x spindump_size:0x%x\n", hdr->signature, hdr->alloc_size, hdr->spindump_offset, hdr->spindump_size); + swd_flags |= SWD_BUF_SIZE_ERROR; goto exit; } stacksSize = hdr->spindump_size; @@ -9720,15 +10269,17 @@ void IOPMrootDomain::sleepWakeDebugDumpFromFile( ) stacksOffset = hdrOffset + hdr->spindump_offset; logOffset = hdrOffset + offsetof(swd_hdr, UUID); logSize = sizeof(swd_hdr)-offsetof(swd_hdr, UUID); + stacksFname = getDumpStackFilename(hdr); + logFname = getDumpLogFilename(hdr); error = sleepWakeDebugCopyFile(vp, ctx, (char *)tmpBuf, tmpBufSize, stacksOffset, - getDumpStackFilename(hdr), stacksSize, hdr->crc); + stacksFname, stacksSize, hdr->crc); if (error == EFAULT) { DMSG("sleepWakeDebugDumpFromFile: Stackshot CRC doesn't match\n"); goto exit; } error = sleepWakeDebugCopyFile(vp, ctx, (char *)tmpBuf, tmpBufSize, logOffset, - getDumpLogFilename(hdr), logSize, 0); + logFname, logSize, 0); if (error) { DMSG("sleepWakeDebugDumpFromFile: Failed to write the log file(0x%x)\n", error); goto exit; @@ -9738,6 +10289,11 @@ exit: // Write just the SleepWakeLog.dump with failure code uint64_t fcode = 0; const char *fname; + swd_hdr hdrCopy; + char *offset = NULL; + int size; + + hdr = &hdrCopy; if (swd_flags & SWD_BOOT_BY_SW_WDOG) { failStat = OSDynamicCast(OSNumber, getProperty(kIOPMSleepWakeFailureCodeKey)); fcode = failStat->unsigned64BitValue(); @@ -9746,10 +10302,17 @@ exit: else { fname = kAppleOSXWatchdogLogFilename; } - memset(PMStatusCode, 0x20, sizeof(PMStatusCode)); // Fill with spaces - PMStatusCode[sizeof(PMStatusCode)-1] = 0xa; // And an end-of-line at the end - snprintf(PMStatusCode, sizeof(PMStatusCode)-1, "Code: 0x%llx", fcode); - sleepWakeDebugSaveFile(fname, PMStatusCode, sizeof(PMStatusCode)); + + offset = (char*)hdr+offsetof(swd_hdr, UUID); + size = sizeof(swd_hdr)-offsetof(swd_hdr, UUID); + memset(offset, 0x20, size); // Fill with spaces + + + snprintf(hdr->spindump_status, sizeof(hdr->spindump_status), "\nstatus: 0x%x", swd_flags); + snprintf(hdr->PMStatusCode, sizeof(hdr->PMStatusCode), "\nCode: 0x%llx", fcode); + snprintf(hdr->reason, sizeof(hdr->reason), "\nStackshot reason: Watchdog\n\n"); + sleepWakeDebugSaveFile(fname, offset, size); + } gRootDomain->swd_lock = 0; @@ -9768,7 +10331,6 @@ void IOPMrootDomain::sleepWakeDebugDumpFromMem(IOMemoryMap *logBufMap) errno_t error = EIO; uint64_t bufSize = 0; swd_hdr *hdr = NULL; - char PMStatusCode[100]; OSNumber *failStat = NULL; if (!OSCompareAndSwap(0, 1, &gRootDomain->swd_lock)) @@ -9784,7 +10346,8 @@ void IOPMrootDomain::sleepWakeDebugDumpFromMem(IOMemoryMap *logBufMap) bufSize = logBufMap->getLength(); if (bufSize <= sizeof(swd_hdr)) { - IOLog("SleepWake log buffer contents are invalid\n"); + IOLog("SleepWake log buffer size is invalid\n"); + swd_flags |= SWD_BUF_SIZE_ERROR; goto exit; } @@ -9807,13 +10370,10 @@ exit: // Write just the SleepWakeLog.dump with failure code uint64_t fcode = 0; const char *sname, *lname; - swd_stackshot_hdr shdr; - - /* Try writing an empty stacks file */ - shdr.magic = SWD_STACKSHOTHDR_MAGIC; - shdr.size = 0; - + swd_hdr hdrCopy; + /* Try writing an empty stacks file */ + hdr = &hdrCopy; if (swd_flags & SWD_BOOT_BY_SW_WDOG) { failStat = OSDynamicCast(OSNumber, getProperty(kIOPMSleepWakeFailureCodeKey)); fcode = failStat->unsigned64BitValue(); @@ -9825,12 +10385,19 @@ exit: sname= kAppleOSXWatchdogStackFilename; } - sleepWakeDebugSaveFile(sname, (char*)(&shdr), sizeof(shdr)); - memset(PMStatusCode, 0x20, sizeof(PMStatusCode)); // Fill with spaces - PMStatusCode[sizeof(PMStatusCode)-1] = 0xa; // And an end-of-line at the end - snprintf(PMStatusCode, sizeof(PMStatusCode)-1, "Code: 0x%llx", fcode); - sleepWakeDebugSaveFile(lname, PMStatusCode, sizeof(PMStatusCode)); + sleepWakeDebugSaveFile(sname, NULL, 0); + + logOffset = (char*)hdr+offsetof(swd_hdr, UUID); + logSize = sizeof(swd_hdr)-offsetof(swd_hdr, UUID); + memset(logOffset, 0x20, logSize); // Fill with spaces + + + snprintf(hdr->spindump_status, sizeof(hdr->spindump_status), "\nstatus: 0x%x", swd_flags); + snprintf(hdr->PMStatusCode, sizeof(hdr->PMStatusCode), "\nCode: 0x%llx", fcode); + snprintf(hdr->reason, sizeof(hdr->reason), "\nStackshot reason: Watchdog\n\n"); + sleepWakeDebugSaveFile(lname, logOffset, logSize); } + gRootDomain->swd_lock = 0; } @@ -9840,7 +10407,7 @@ IOMemoryMap *IOPMrootDomain::sleepWakeDebugRetrieve( ) IOMemoryDescriptor * desc = NULL; IOMemoryMap * logBufMap = NULL; - uint32_t len; + uint32_t len = INT_MAX; addr64_t data[3]; uint64_t bufSize = 0; uint64_t crc = 0; @@ -9869,8 +10436,9 @@ IOMemoryMap *IOPMrootDomain::sleepWakeDebugRetrieve( ) goto exit; } } - else if (len == sizeof(addr64_t)*3) + else if (len == sizeof(addr64_t)*3) { PEReadNVRAMProperty(kIOSleepWakeDebugKey, data, &len); + } else { DLOG("Invalid sleepWakeDebug note length(%d)\n", len); goto exit; @@ -9886,7 +10454,8 @@ IOMemoryMap *IOPMrootDomain::sleepWakeDebugRetrieve( ) paddr = data[2]; if ( (bufSize <= sizeof(swd_hdr)) ||(bufSize > SWD_BUF_SIZE) || (crc == 0) ) { - IOLog("SleepWake log buffer contents are invalid\n"); + IOLog("SleepWake log buffer size is invalid\n"); + swd_flags |= SWD_BUF_SIZE_ERROR; return NULL; } @@ -9899,6 +10468,7 @@ IOMemoryMap *IOPMrootDomain::sleepWakeDebugRetrieve( ) if (desc == NULL) { IOLog("Fail to map SleepWake log buffer\n"); + swd_flags |= SWD_INTERNAL_FAILURE; goto exit; } @@ -9909,13 +10479,15 @@ IOMemoryMap *IOPMrootDomain::sleepWakeDebugRetrieve( ) if ( (logBufMap->getLength() <= sizeof(swd_hdr)) || (vaddr == NULL) ) { IOLog("Fail to map SleepWake log buffer\n"); + swd_flags |= SWD_INTERNAL_FAILURE; goto exit; } hdr = (swd_hdr *)vaddr; if (hdr->spindump_offset+hdr->spindump_size > bufSize) { - IOLog("SleepWake log buffer contents are invalid\n"); + IOLog("SleepWake log header size is invalid\n"); + swd_flags |= SWD_HDR_SIZE_ERROR; goto exit; } @@ -9924,6 +10496,7 @@ IOMemoryMap *IOPMrootDomain::sleepWakeDebugRetrieve( ) hdr->spindump_size); if (newcrc != crc) { IOLog("SleepWake log buffer contents are invalid\n"); + swd_flags |= SWD_DATA_CRC_ERROR; goto exit; } @@ -9947,6 +10520,16 @@ exit: void IOPMrootDomain::sleepWakeDebugTrig(bool restart) { + uint32_t wdog_panic = 1; + + if (restart) { + if (PE_parse_boot_argn("swd_panic", &wdog_panic, sizeof(wdog_panic)) && + (wdog_panic == 0)) { + return; + } + panic("Sleep/Wake hang detected"); + return; + } } void IOPMrootDomain::takeStackshot(bool restart, bool isOSXWatchdog, bool isSpinDump)