linux-kernel - getnstimeofday stuck for several milliseconds?

lists.openwall.net		lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC
Open Source and information security mailing list archives

Hash Suite: Windows password security audit tool. GUI, reports in PDF.

[<prev] [next>] [thread-next>] [day] [month] [year] [list]

Date:	Mon, 05 Nov 2012 09:51:01 +0100
From:	David Henningsson <david.henningsson@...onical.com>
To:	linux-kernel@...r.kernel.org
CC:	tglx@...utronix.de, johnstul@...ibm.com
Subject: getnstimeofday stuck for several milliseconds?

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

It seems to me that sometimes we get stuck for several milliseconds 
inside the getnstimeofday function - this was seen on both the 9 ms and 
the 20 ms trace. This looks like a bug to me, and as I'm not sure on how 
to best debug it further, and therefore I'm asking for help (or a bug 
fix!) here.

For reference, the 9 ms trace was from a ~2 year old laptop (core i3 
cpu) running 3.7rc2 vanilla/mainline kernel, and the 20 ms trace was 
from an ~1 year old Atom-based machine running the 3.2-ubuntu kernel. 
While tracing was enabled, I was running a libSDL game for a minute or two.

Thanks in advance for looking into this, and let me know if you need 
further information, or anything else I can do to help sorting this one out.

-- 
David Henningsson, Canonical Ltd.
https://launchpad.net/~diwic

[1] http://pastebin.se/6iMRdDfR
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@...r.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/