Bug 446944 - Max latency near 1ms encountered while running cyclictest
Max latency near 1ms encountered while running cyclictest
Product: Red Hat Enterprise MRG
Classification: Red Hat
Component: realtime-kernel (Show other bugs)
All Linux
urgent Severity urgent
: 1.0
: ---
Assigned To: Steven Rostedt
: Reopened
Depends On:
Blocks: 447235
  Show dependency treegraph
Reported: 2008-05-16 14:17 EDT by Clark Williams
Modified: 2008-08-14 16:51 EDT (History)
6 users (show)

See Also:
Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
Last Closed: 2008-08-14 16:51:43 EDT
Type: ---
Regression: ---
Mount Type: ---
Documentation: ---
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---

Attachments (Terms of Use)
allow delay to preempt (4.49 KB, patch)
2008-05-27 13:26 EDT, Steven Rostedt
no flags Details | Diff

  None (edit)
Description Clark Williams 2008-05-16 14:17:01 EDT
Description of problem:
While running cyclictest on various systems (with load in the background), large
(>=1ms) latencies can be observed

Version-Release number of selected component (if applicable):

How reproducible:
Sometimes takes a while but in general show up in less than 5 minutes of runtime

Steps to Reproduce:
1. Boot RT kernel
2. run: cyclictest -n -p 90 -t 4
3. run: (cd LTPdir; while true; do ./runltp; done)
4. run: (cd kernelsrc; while true; do make clean bzImage modules; done)

Actual results:
One of the four cyclictest threads will eventually show a latency in the
900us-1ms range. Avg latency on a dual 2GHz Opteron system will stay in the
single microseconds:

$ sudo cyclictest -n -p 90 -t 4
0.11 0.18 0.14 1/158 14964          

T: 0 ( 3419) P:90 I:1000 C: 819087 Min:      4 Act:    5 Avg:    5 Max:      40
T: 1 ( 3420) P:89 I:1500 C: 546059 Min:      4 Act:    6 Avg:    5 Max:     960
T: 2 ( 3421) P:88 I:2000 C: 409544 Min:      4 Act:    4 Avg:    5 Max:      32
T: 3 ( 3422) P:87 I:2500 C: 327635 Min:      4 Act:    5 Avg:    5 Max:      30

Expected results:
No Max Latency over 100us

Additional info:

I've run this test on a number of the test boxes in Huntsville and all have
exhibited this behavior, with production kernel-rt packages.
Comment 1 Steven Rostedt 2008-05-18 19:33:24 EDT
Clark, try this:

 # sysctl kernel.sched_nr_migrate=2

And see if that solves you problem. With the new coming out (with
latency stealing), I was hitting that 900+ all the time. Looking at ftrace, I
found that the load balancing was taking up to 400us at a time. Compounded by
4way or more boxes that can be running this balancing at the same time. My trace
showed that the double_rq_lock took 424us!!! during this balance code and that
was because the CPU of the rq it was trying to grab was also trying to do balancing.

This needs to be noted (Lana ;-)
Comment 2 Steven Rostedt 2008-05-18 20:42:55 EDT
Nevermind, I just hit the 900us+ latency with sched_nr_migrate=2. I'll look
deeper into it.
Comment 3 Clark Williams 2008-05-20 20:57:48 EDT
What ftrace setup are you using to try and trap this thing? If you can post a
setup here, I'll try and duplicate it and get a trace for you.
Comment 4 Clark Williams 2008-05-22 16:40:15 EDT
elevating to blocker status
Comment 5 Steven Rostedt 2008-05-27 13:26:48 EDT
Created attachment 306803 [details]
allow delay to preempt

Seems that x86 delay uses tsc, and Andrew Morton made the delay non-preempt to
keep problems from non-synced tsc's from causing problems on SMP. This
disabling of preemption caused us large latencies.

The patch breaks this preemption and removes the 1ms latencies that we are
Comment 6 Steven Rostedt 2008-05-27 13:28:05 EDT
Changing status to MODIFIED to show that this bug is considered resolved, but
needs testing. The -rt11 version will contain this patch.
Comment 7 Clark Williams 2008-05-28 17:59:37 EDT
kernel-rt- was built with -rt11 and is currently under test.
Early signs show that the __delay fix has addressed this bug.
Comment 8 Clark Williams 2008-07-02 10:42:54 EDT
fixed in GA
Comment 9 Beth Uptagrafft 2008-07-28 12:37:08 EDT
Need to reopen and set state to Modified for 1.0.1 release.
Comment 13 Beth Uptagrafft 2008-08-14 16:51:43 EDT
Closing.  Fixed in GA.

Note You need to log in before you can comment on or make changes to this bug.