I finally found the root cause of an Asterisk timing issue that looked like a Linux/kernel/timer problem — but it was not.
The symptom was that Asterisk timing would go off. At first, it looked like something low-level: kernel scheduler, VM timing, timerfd, CPU power states, realtime priority, or logging overhead.
I went through a long list of tests before finding the real cause:
-
Updated the kernel.
-
Tried moving to a realtime kernel.
-
Tested different Asterisk timing sources.
-
Changed Intel C-state / power-state settings.
-
Tried pinning Asterisk to specific CPU cores.
-
Ran Asterisk with realtime scheduling.
-
Reduced/stopped Asterisk logging to rule out log I/O delays.
None of those solved it.
Then I tested the timing source itself outside of Asterisk. My standalone timerfd test was configured for 100 Hz, and it was stable:
ticks=100 in 1000ms (expected 100)
That did not mean Asterisk should also show 100 ticks. It only proved that the Linux timer source could deliver the rate requested by the standalone test.
Inside Asterisk, the timing test/debug path I was watching expected 50 ticks per second. When healthy, Asterisk showed:
It has been 1000 milliseconds, and we got 50 timer ticks
But when the problem happened, Asterisk showed missed/late tick totals:
It has been 1006 milliseconds, and we got 43 timer ticks
It has been 1000 milliseconds, and we got 44 timer ticks
It has been 1000 milliseconds, and we got 48 timer ticks
I also saw debug from the timerfd acknowledge path:
Expected to acknowledge 1 ticks but got 2 instead
Expected to acknowledge 1 ticks but got 3 instead
That was an important clue. It did not look like timerfd stopped firing. It looked like Asterisk was sometimes late getting back to read/acknowledge the timerfd, so multiple timer expirations had accumulated by the time Asterisk serviced it.
This matched the tick deficit above. If Asterisk is late acknowledging a few timerfd expirations during the one-second window, the higher-level result can show 43–48 ticks instead of the expected 50. The ticks were not simply vanishing; Asterisk was not servicing them promptly.
So the issue was not that Asterisk showed 50 while the standalone test showed 100. Those were different expected rates. The issue was that Asterisk sometimes expected 50 ticks and only received 43, 44, or 48, and sometimes expected to acknowledge 1 timer expiration but found 2 or 3 had already accumulated.
That shifted the investigation away from “bad kernel timer” and toward “what is Asterisk doing internally during the bad window?”
At that point I compiled Asterisk with lock debugging enabled and ran:
core show locks
during the bad timing window.
The strongest single sample was not just that voicemail-related locks existed. It showed a thread actually waiting in the stasis state path while the call path came from voicemail/MWI publishing:
Waiting for Lock ... stasis_state.c ... __state_find_or_add manager->states
ast_mwi_publish_by_mailbox
ast_publish_mwi_state_full
app_voicemail_odbc.so
Other samples during the same bad windows repeatedly showed:
mb_poll_thread
ast_mwi_state_callback_subscribed
internal_ao2_traverse
res_pjsip_mwi
So I did not conclude that the Linux timer itself was bad, and I also did not claim that I had traced the exact timer thread being blocked. The evidence showed that Asterisk was doing periodic voicemail/MWI/stasis work during the same windows where timing ticks were late.
The setting that caused that periodic work was:
pollmailboxes=yes
with:
pollfreq=30
That means every 30 seconds Asterisk was polling voicemail mailboxes, walking MWI subscriptions, checking voicemail counts through ODBC, and publishing MWI updates.
After changing:
pollmailboxes=yes
to:
pollmailboxes=no
the timing immediately became stable.
The main lesson: not every Asterisk timing problem is really a kernel, VM, or timer-source problem.
The troubleshooting path that finally helped was:
-
Prove the OS timer source works outside Asterisk.
-
Compare that with what Asterisk expects internally.
-
Capture the bad window, not just the healthy state.
-
Look for late timer acknowledgements, not only total tick counts.
-
Compile with lock debugging if needed.
-
Run
core show lockswhile timing is actually bad. -
Look for repeated internal work that correlates with the missed ticks.
In my case, the hidden cause was voicemail polling and MWI updates with ODBC not the kernel.