Repeating timer firing way to fast


Jonathan Taylor
 

Hi all,


I’ve been trying to figure out what happened on an overnight run of the code that drives our scientific experiment, and I’m seeing logs that imply that a timer has been firing much more rapidly than intended. I’m hoping somebody can help me figure out why, and what I should be changing.

The calls that set up the timer can be condensed down to:

timerSource = dispatch_source_create(DISPATCH_SOURCE_TYPE_TIMER, 0, DISPATCH_TIMER_STRICTdispatch_get_main_queue());
dispatch_source_set_event_handler(timerSource, myHandler);
dispatch_source_set_timer(timerSource, dispatch_time(DISPATCH_TIME_NOWrepeatIntervalNs), repeatIntervalNs, flexibilityNs);

where repeatIntervalNs is 4*NSEC_PER_SEC and flexibilityNs is 2*NSEC_PER_SEC. The CPU is under fairly high load from multithreaded code all night, but normally the timer fires on average every 4 seconds. Note that I have specified DISPATCH_TIMER_STRICT in a perhaps-misguided attempt to protect against the fact that occasionally, under unusually high load I presume, the timer was not firing for 30 seconds or more at a time. However, the problem that I am seeing in practice is that (in this overnight run, at least) the timer was firing at a rate of up to 200 times per second! All I am trying to achieve with this periodic timer is to check in with the secondary process and provide it with a status update.

The perhaps-unusual thing here is that the timer callback makes a function call via an NSConnection to a secondary process. Sometimes that secondary process is busy (for seconds at a time) and therefore the timer callback blocks. My theory is that what is happening is that the OS is building up a “backlog” of timer callbacks that it wants to make - many more, indeed, than than it would make if it really was firing every ~4secs. 

None of this is a huge problem (except that it’s led to an enormous log file!), but it makes me worry that I am going about all of this the wrong way. What do people think? Is this a terrible way to achieve what I want to achieve, for some reason? Does it seem plausible that the number of timer callbacks would be disproportionately high like this? Any suggestions most welcome!

Cheers
Jonny


Jon Gotow
 

Not knowing how your code is structured, this may be a dumb question, but just to check:

Are you certain that you're not creating multiple timers somehow? I've mistakenly done this when creating timers in response to an event and the event occurs in extra, unexpected circumstances.

- Jon

On May 22, 2018, at 5:15 AM, Jonathan Taylor <jonathan.taylor@...> wrote:

Hi all,


I’ve been trying to figure out what happened on an overnight run of the code that drives our scientific experiment, and I’m seeing logs that imply that a timer has been firing much more rapidly than intended. I’m hoping somebody can help me figure out why, and what I should be changing.

The calls that set up the timer can be condensed down to:

timerSource = dispatch_source_create(DISPATCH_SOURCE_TYPE_TIMER, 0, DISPATCH_TIMER_STRICT, dispatch_get_main_queue());
dispatch_source_set_event_handler(timerSource, myHandler);
dispatch_source_set_timer(timerSource, dispatch_time(DISPATCH_TIME_NOW, repeatIntervalNs), repeatIntervalNs, flexibilityNs);

where repeatIntervalNs is 4*NSEC_PER_SEC and flexibilityNs is 2*NSEC_PER_SEC. The CPU is under fairly high load from multithreaded code all night, but normally the timer fires on average every 4 seconds. Note that I have specified DISPATCH_TIMER_STRICT in a perhaps-misguided attempt to protect against the fact that occasionally, under unusually high load I presume, the timer was not firing for 30 seconds or more at a time. However, the problem that I am seeing in practice is that (in this overnight run, at least) the timer was firing at a rate of up to 200 times per second! All I am trying to achieve with this periodic timer is to check in with the secondary process and provide it with a status update.

The perhaps-unusual thing here is that the timer callback makes a function call via an NSConnection to a secondary process. Sometimes that secondary process is busy (for seconds at a time) and therefore the timer callback blocks. My theory is that what is happening is that the OS is building up a “backlog” of timer callbacks that it wants to make - many more, indeed, than than it would make if it really was firing every ~4secs.

None of this is a huge problem (except that it’s led to an enormous log file!), but it makes me worry that I am going about all of this the wrong way. What do people think? Is this a terrible way to achieve what I want to achieve, for some reason? Does it seem plausible that the number of timer callbacks would be disproportionately high like this? Any suggestions most welcome!

Cheers
Jonny



Quincey Morris
 

On May 22, 2018, at 04:15 , Jonathan Taylor <jonathan.taylor@...> wrote:

and therefore the timer callback blocks

It seems to me that this could be regarded as a bug in your design. The consequence of blocking, at a higher conceptual level, is that it destroys the concept of timing which is essential to your task.

One alternative is to use the timer callback *only* to decide whether it has been 4 or more seconds since the last time the secondary process action finished (or, more than 4 seconds since it last started, *and* that it has finished), and, if so, to trigger the action asynchronously. The precise details will depend on how you want the system to behave in the face of delays.

Or, you could switch to a recurring NSTimer. That has an API contract about what happens when scheduled firings are missed:

"After a repeating timer fires, it schedules the next firing for the nearest future date that is an integer multiple of the timer interval after the last scheduled fire date, within the specified tolerance. If the time taken to call out to perform a selector or invocation is longer than the specified interval, the timer schedules only the next firing; that is, the timer doesn't attempt to compensate for any missed firings that would have occurred while calling the specified selector or invocation.”


Jonathan Taylor
 

Thankyou both for your replies. I'm as sure as I can be that I'm not creating multiple timers, but I certainly checked for that. I appreciate that this is probably not the best design, due to the blocking issue. Thanks for your suggestion of NSTimer, though. That might be a nice quick fix until I can face a proper redesign!