2 Replies
      Latest reply on Oct 16, 2019 5:11 AM by Columbo
      Columbo Level 1 Level 1 (10 points)

        We've been getting a crash on an app under development which is producing logs with the message: "45001 wakeups over the last 174 seconds (258 wakeups per second average), exceeding limit of 150 wakeups per second over 300 seconds".

         

        We have narrowed down the cause of our crash to some temporary debug code that was firing more-than-usual numbers of analytics events. Our analytics system uses AWS Kinesis Firehose: https://github.com/aws-amplify/aws-sdk-ios/tree/master/AWSKinesis

         

        Obviously we can fix by disabling the debug code, but we'd like to have a better understanding of the problem so that we can make our code (or the AWS code) more robust. Additionally, we know of at least one end user that has experienced similar issues on a released title and we were unable to help them get our product working on their device - I now suspect their problems may have been related.

         

        Basically, I don't know what a wakeup is in this context, so I therefore don't understand how to go about controlling the number that we trigger. It must refer to something other than ordinary multi-threading activity, because 150 thread switches per second is such a low limit that it would effectively prohibit multi-threading (the limit is only 2.5 per frame at 60fps!). I also don't think it can refer to background execution because our app doesn't do any background execution and the crashes are not associated with multitasking at all.

         

        Can anyone tell me what a wakeup is in this context? And maybe give me advice to help me find the code that is causing them?

        • Re: Wakeups limit exceeded
          eskimo Apple Staff Apple Staff (12,455 points)

          Can anyone tell me what a wakeup is in this context?

          I’ve been wondering about this myself, so I spent some time digging into the origin of this number.  This concept comes from the kernel, and you can look at how it’s calculated in the Darwin open source.  Specifically, the droid you’re looking for here is the interrupt_wakeups as dispatch by the SENDING_NOTIFICATION__THIS_PROCESS_IS_CAUSING_TOO_MANY_WAKEUPS routine (you couldn’t get more descriptive than that!) in the osfmk/kern/task.c [1] and incremented in thread_unblock in osfmk/kern/sched_prim.c.  In short, it seems to count the number of times that a blocked thread was unblocked because of an ‘interrupt’ [2].

          And maybe give me advice to help me find the code that is causing them?

          In situations like this, the System Trace instrument is your friend.

          Share and Enjoy

          Quinn “The Eskimo!”
          Apple Developer Relations, Developer Technical Support, Core OS/Hardware
          let myEmail = "eskimo" + "1" + "@apple.com"

          [1] The links here are to the latest kernel source currently available, which is for macOS 10.14.1 and thus roughly corresponds to iOS 12.1.  I’ve no reason to believe this has changed in the 2019 OS releases.

          [2] In sneer quotes because interrupts are a complex thing in XNU.

            • Re: Wakeups limit exceeded
              Columbo Level 1 Level 1 (10 points)

              Thanks for the response. To update on this:

               

              • I tried the System Trace instrument and was able to view the wakeups that occurred, but I still couldn't work out what the ultimate cause of the wakeups was. If I had to guess now after digging into the AWS kinesis code I'd say GCD or NSURLSession seem the most likely sources.
              • We did eventually get a more normal crash report (as opposed to the microstackshots report with the wakeups alert). The crash report led us to find a race condition in our analytics code (one thread wrote to an NSMutableArray while another thread read from it).
              • After fixing the race condition we could no longer reproduce any crashes. This leads me to believe that the wakeups alert is a bit of a red herring. Reading around the kernel code that eskimo linked to, it looks like the wakeups count can either be fatal or be a warning. I now suspect that it was just a warning that didn't have anything to do with the crashes we were experiencing.
              • I also found that our application had some code that was intended to prevent excessive uploading of analytics, but it had muddled milliseconds and seconds, so it wasn't effective. After verifying that crashes were no longer reproducible based on the race condition fix alone, we then fixed this bug. So, hopefully we've fixed the wakeups count too but we haven't really verified that.