[ag-automation] Strange Variation in Latency Values

Thu Dec 13 14:52:14 CET 2012

Hello,

We are working on Freescale MPC8313ERDB board. We have ported 3.0.46-rt69 kernel on the same. While testing the RT-Patch using cyclictest utility we got some strange latency values. When 'histogram' option in cyclictest is disabled, we get max latency in range of 100 to 200us whereas if we enable 'histogram' option (-h) we get max latency of around 50ms. What could be the possible reason behind this much variation? 

The trace is as follows:
******************************************************************************
-sh-2.05b# echo 1 > tracing_on; /opt/cyclictest -l100000 -p95 -Q -m -n -i500 -t8; echo 0 > tracing_on
policy: fifo: loadavg: 3.26 2.40 1.25 1/52 1018          

T: 0 ( 1011) P:95 I:500 C: 100000 Min:     64 Act:   87 Avg:   93 Max:     159
T: 1 ( 1012) P:94 I:1000 C:  50200 Min:    103 Act:  159 Avg:  140 Max:     206
T: 2 ( 1013) P:93 I:1500 C:  33343 Min:     78 Act:  164 Avg:  155 Max:     301
T: 3 ( 1014) P:92 I:2000 C:  24901 Min:     54 Act:  103 Avg:  124 Max:     256
T: 4 ( 1015) P:91 I:2500 C:  19827 Min:     55 Act:  100 Avg:  169 Max:     299
T: 5 ( 1016) P:90 I:3000 C:  16436 Min:    213 Act:  251 Avg:  335 Max:     558
T: 6 ( 1017) P:89 I:3500 C:  14011 Min:     54 Act:  107 Avg:  191 Max:     621
T: 7 ( 1018) P:88 I:4000 C:  12188 Min:     63 Act:  120 Avg:  172 Max:     683

-sh-2.05b# echo 1 > tracing_on; /opt/cyclictest -l100000 -p95 -Q -m -n -i500 -h5 -t8; echo 0 > tracing_on
policy: fifo: loadavg: 4.44 1.97 1.27 1/47 1028           

T: 0 ( 1021) P:95 I:500 C: 100000 Min:     69 Act:   77 Avg: 1227 Max:   49865
T: 1 ( 1022) P:94 I:500 C: 100000 Min:     75 Act:  118 Avg: 1344 Max:   51286
T: 2 ( 1023) P:93 I:500 C: 100000 Min:    101 Act:  102 Avg: 1501 Max:   52968
T: 3 ( 1024) P:92 I:500 C: 100000 Min:      4 Act:   79 Avg: 1536 Max:   55277
T: 4 ( 1025) P:91 I:500 C: 100000 Min:     73 Act:   91 Avg: 2141 Max:   58936
T: 5 ( 1026) P:90 I:500 C: 100000 Min:      5 Act:   98 Avg: 3596 Max:   70001
T: 6 ( 1027) P:89 I:500 C:  93974 Min:     46 Act:   65 Avg:12742559 Max:26747703
T: 7 ( 1028) P:88 I:500 C:  89975 Min:    130 Act:  159 Avg:21059281 Max:42451203
# Histogram
000000 000000   000000  000000  000000  000000  000000  000000  000000
000001 000000   000000  000000  000000  000000  000000  000000  000000
000002 000000   000000  000000  000000  000000  000000  000000  000000
000003 000000   000000  000000  000000  000000  000000  000000  000000
000004 000000   000000  000000  000001  000000  000000  000000  000000
# Total: 000000000 000000000 000000000 000000001 000000000 000000000 000000000 000000000
# Min Latencies: 00069 00075 00101 00004 00073 00005 00046 00130
# Avg Latencies: 01227 01344 01501 01536 02141 03596 12739577 21054133
# Max Latencies: 49865 51286 52968 55277 58936 70001 26747703 42451203
# Histogram Overflows: 100000 100000 100000 99999 100000 100000 93996 89997
-sh-2.05b# cat trace                                                           
# tracer: wakeup_rt
#
# wakeup_rt latency trace v1.1.5 on 3.0.46-rt69
# --------------------------------------------------------------------
# latency: 51043 us, #4/4, CPU#0 | (M:preempt VP:0, KP:0, SP:0 HP:0)
#    -----------------
#    | task: cyclictest-1027 (uid:0 nice:0 policy:1 rt_prio:89)
#    -----------------
#
#                  _------=> CPU#            
#                 / _-----=> irqs-off        
#                | / _----=> need-resched    
#                || / _---=> hardirq/softirq 
#                ||| / _--=> preempt-depth   
#                |||| / _--=> migrate-disable
#                ||||| /     delay           
#  cmd     pid   |||||| time  |   caller     
#     \   /      |||||  \   |   /          
cyclicte-1025    0d.h3.    3us+:   1025:120:R   + [000]  1027: 10:S cyclictest
cyclicte-1025    0d.h3.   11us!: try_to_wake_up <-wake_up_process
cyclicte-1026    0d..3. 51033us+: __schedule <-schedule
cyclicte-1026    0d..3. 51040us :   1026:  9:S ==> [000]  1027: 10:R cyclictest
-sh-2.05b# 
*******************************************************************************

If anybody could give us a hint or so which would help us to debug the issue further.

Kind Regards,
RahulEmail Disclaimer:
  ---------------------------

This e-mail and any files transmitted with it are for the sole use of the intended recipient(s) and may contain confidential and  privileged information. Computer viruses can be transmitted via email.The recipient should check this email and any  attachments for the presence of viruses. The company accepts no liability for any damage caused by any virus transmitted by this email.