Deferring code execution in OSX 10.10

I am facing a very strange issue that affects my code that only runs on OSX 10.10. I have seen this anomaly on over 25 OSX 10.10 systems that my code is running on, whereas the same code did not exhibit this behavior until the update (10.7). Also, this question is not 100% reproducible as it happens at random - 0-5% of the time. When testing code on a machine, there is nothing critical or cpu. Even if something else is going on, the very fact that the delays I am experiencing are so ludicrously long that this conclusion seems suspicious. Anyway, without further ado, take a look at the following NSLog printouts:

12:00:05.766 MyApp[59957:6540517] Time_To_Wait: 679000000, Fire_Date: 270946738287700, Cur_Date: 270946059302734
12:00:26.446 MyApp[59957:6540517] Resume...

      

        
        
        
      

    

Time in nanoseconds. According to NSLog timestamps, we actually ended up expecting 20.68 seconds instead of the desired 0.679 seconds. Now let's take a look at the code:

NSLog(@"Time_To_Wait: %lld, Fire_Date: %lld, Cur_Date: %lld", time_to_wait, fire_date, mach_absolute_time());
mach_wait_until(fire_date);
NSLog(@"Resume...");

      

        
        
        
      

    

If you're wondering what mach_wait is, this is the default high resolution timer. Just turn on

#include <mach/mach.h>
#include <mach/mach_time.h>

      

        
        
        
      

    

But it doesn't matter because I experienced the same problem if I replaced mach_wait_until with:

• sleep()
  
  
• usleep()
  
  
• [NSThread sleepForTimeInterval:]
  
  
• GCD dispatch_after(,^{});
  
  
• mach_wait_until()
  
  

It doesn't matter which delay method I try, I use NSLog

to print my "delay" value to the console as a health check to ensure the correct number of ms, then run one of the above ~ 95% of the time it behaves according to specification. But sometimes, randomly, I get a delay with a delay, for example 10-20 seconds. What gives? Is this a Yosemite core issue? Again, I've never experienced this w / same code working on 10.7. And I have tested all the above methods to delay code execution.

UPDATE:

After commenting the advice, I went ahead and sudo dtruss -f -e sudo -u USER MyApp 2> ~/myapps.log

. As usual, most mach_wait and sleep behaved as intended. So to make it easier to identify, I added in the check where if the actual sleep duration is> 3 times what it should be, it prints DELAY ISSUE. Worked my program through and did a search for the delay issue. The following are the most common system calls (dtruss output) that occur between printing the log immediately preceding and executing the mach_wait statement:

• 99613 / 0xcf33b9: 30250 __semwait_signal (0xD07, 0x0, 0x1) = -1 Err # 60
• 99613 / 0xcf33b9: 16 workq_kernreturn (0x20, 0x0, 0x1) = 0 0

There are about ~ 250+ of the above two calls. Probably a few more workers than __semwait's. It usually takes about 30,000 units of time for a semester to complete, whatever that is. Dunno like dtruss times. They make up the bulk of the challenges.

• 752 / 0xcf3320: 2787191 kevent64 (0x3, 0x0, 0x0) = 1 0
• 752 / 0xcf335d: 189948 select (0x40, 0x7FC080E18220, 0x7FC080E13B40, 0x0, 0x0) = 1 0
• 752 / 0xcf335d: 1648403 select (0x40, 0x7FC080E18220, 0x7FC080E13B40, 0x0, 0x0) = 1 0

These three system calls took the longest amount of time units. And each of them appeared once at the exit during our ~ 20 seconds wait deficit.

Not sure what to do with the above = X