On 11/05/2012 12:51 AM, David Henningsson wrote:The more I think about it, I'm pretty sure this is the case:Hi LKML,
I'm trying to make audio more useful in everyday low-latency scenarios such as gaming or VOIP.
While doing so, I ran the wakeup_rt tracer, to track the time from PulseAudio requesting wakeup (through hrtimers), to the thread actually running.
I'm not sure how much overhead added by the wakeup_rt tracer itself, but I got 9 ms on one machine and 20 ms on another, which I consider to be quite a lot even for a standard kernel (i e without RT or other special configuration).
The 9 ms example is pastebinned at [1], and here's where we get stuck for most of the time:
<idle>-0 3d... 1105us : ktime_get_real <-intel_idle
<idle>-0 3d... 1106us!: getnstimeofday <-ktime_get_real
<idle>-0 3d... 7823us : ktime_get_real <-intel_idle
<idle>-0 3d... 7890us : ktime_get_real <-intel_idle
<idle>-0 3d... 7891us!: getnstimeofday <-ktime_get_real
<idle>-0 3d... 9023us : ktime_get_real <-intel_idle
Looking at the trace you posted here: http://pastebin.se/6iMRdDfR
The trace also looks like its the cpuidle to interrupt transition where you're seeing this. I sort of wonder if its mis-attributing the idle time to the getnstimeofday()? Mainly because you don't seem to spend much time in intel_idle() otherwise.
Or maybe we're both misreading it and its saying there's a delay between the first ktime_get_real() from intel_idle() to the second call of ktime_get_real(), between which we're in deep idle (which would make sense)?