* [Xenomai-help] strange latency output (xenomai-2.4.5) @ 2009-02-10 16:49 Georg Gottleuber 2009-02-10 16:47 ` Gilles Chanteperdrix 0 siblings, 1 reply; 8+ messages in thread From: Georg Gottleuber @ 2009-02-10 16:49 UTC (permalink / raw) To: xenomai Hi, I recently port a ARM926EJ-S mach to Xenomai (like described in http://www.xenomai.org/index.php/I-pipe:ArmPorting). While testing with latency I got this output: # /usr/xenomai/bin/latency -p 1000 -h -s -H 500 -t 1 == Sampling period: 1000 us == Test mode: in-kernel periodic task == All results in microseconds warming up... RTT| 00:00:01 (in-kernel periodic task, 1000 us period, priority 99) RTH|-----lat min|-----lat avg|-----lat max|-overrun|----lat best|---lat worst RTD| 78.992| 104.308| 124.131| 0| 78.992| 124.131 ... RTD| 14.678| 68.413| 96.275| 0| 9.528| 155.321 RTD| 84.046| 116.435| 175.192| 0| 9.528| 182.139 ... ^^^^^^^ ^^^^^^^ Some time earlier I had a problem in my clock code and got this: # /usr/xenomai/bin/latency -p 1000 -h -s -H 500 -T 900 == Sampling period: 1000 us == Test mode: periodic user-mode task == All results in microseconds warming up... RTT| 00:00:01 (periodic user-mode task, 1000 us period, priority 99) RTH|-----lat min|-----lat avg|-----lat max|-overrun|----lat best|---lat worst RTD| 130.208| 131.944| 135.416| 0| 130.208| 135.416 RTD| 63.368| 132.812| 155.381| 0| 63.368| 155.381 ... RTD| 33.854| 38.194| 55.555| 0| 29.513| 236.979 RTD| 32.986| 38.194| 62.500| 56| 29.513| 56978.298 RTD| 33.854| 38.194| 50.347| 56| 29.513| 56978.298 ... This is a very rare behavior. Normally I got (with bad clock code): RTD| 36.458| 44.270| 168.402| 0| 33.854| 208.333 RTD| 37.326| 156.250| 56973.958| 28| 33.854| 56973.958 RTD| 36.458| 46.875| 164.062| 28| 33.854| 56973.958 I'm using xenomai-2.4.5 and made a ping test from the host: ping -l 7 -q -s 10 -f <target IP> Has anybody seen this behavior before? Kind regards, Georg Gottleuber ^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: [Xenomai-help] strange latency output (xenomai-2.4.5) 2009-02-10 16:49 [Xenomai-help] strange latency output (xenomai-2.4.5) Georg Gottleuber @ 2009-02-10 16:47 ` Gilles Chanteperdrix 2009-02-10 17:22 ` Georg Gottleuber 0 siblings, 1 reply; 8+ messages in thread From: Gilles Chanteperdrix @ 2009-02-10 16:47 UTC (permalink / raw) To: Georg Gottleuber; +Cc: xenomai Georg Gottleuber wrote: > Hi, > > I recently port a ARM926EJ-S mach to Xenomai > (like described in http://www.xenomai.org/index.php/I-pipe:ArmPorting). > > While testing with latency I got this output: > # /usr/xenomai/bin/latency -p 1000 -h -s -H 500 -t 1 > == Sampling period: 1000 us > == Test mode: in-kernel periodic task > == All results in microseconds > warming up... > RTT| 00:00:01 (in-kernel periodic task, 1000 us period, priority 99) > RTH|-----lat min|-----lat avg|-----lat max|-overrun|----lat best|---lat worst > RTD| 78.992| 104.308| 124.131| 0| 78.992| 124.131 > ... > RTD| 14.678| 68.413| 96.275| 0| 9.528| 155.321 > RTD| 84.046| 116.435| 175.192| 0| 9.528| 182.139 > ... ^^^^^^^ ^^^^^^^ I do not understand, what is wrong with these values ? -- Gilles. ^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: [Xenomai-help] strange latency output (xenomai-2.4.5) 2009-02-10 16:47 ` Gilles Chanteperdrix @ 2009-02-10 17:22 ` Georg Gottleuber 2009-02-10 17:21 ` Gilles Chanteperdrix 2009-02-10 17:29 ` Gilles Chanteperdrix 0 siblings, 2 replies; 8+ messages in thread From: Georg Gottleuber @ 2009-02-10 17:22 UTC (permalink / raw) To: xenomai Gilles Chanteperdrix schrieb: > Georg Gottleuber wrote: >> Hi, >> >> I recently port a ARM926EJ-S mach to Xenomai >> (like described in http://www.xenomai.org/index.php/I-pipe:ArmPorting). >> >> While testing with latency I got this output: >> # /usr/xenomai/bin/latency -p 1000 -h -s -H 500 -t 1 >> == Sampling period: 1000 us >> == Test mode: in-kernel periodic task >> == All results in microseconds >> warming up... >> RTT| 00:00:01 (in-kernel periodic task, 1000 us period, priority 99) >> RTH|-----lat min|-----lat avg|-----lat max|-overrun|----lat best|---lat worst >> RTD| 78.992| 104.308| 124.131| 0| 78.992| 124.131 >> ... >> RTD| 14.678| 68.413| 96.275| 0| 9.528| 155.321 >> RTD| 84.046| 116.435| 175.192| 0| 9.528| 182.139 >> ... ^^^^^^^ ^^^^^^^ > > I do not understand, what is wrong with these values ? It thought, if "lat max" of the current interval is bigger than "lat worst", this "lat max" updates the "lat worst". So I ask myself, out of which interval comes the updated 182 value? ^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: [Xenomai-help] strange latency output (xenomai-2.4.5) 2009-02-10 17:22 ` Georg Gottleuber @ 2009-02-10 17:21 ` Gilles Chanteperdrix 2009-02-10 17:29 ` Gilles Chanteperdrix 1 sibling, 0 replies; 8+ messages in thread From: Gilles Chanteperdrix @ 2009-02-10 17:21 UTC (permalink / raw) To: Georg Gottleuber; +Cc: xenomai Georg Gottleuber wrote: > > Gilles Chanteperdrix schrieb: >> Georg Gottleuber wrote: >>> Hi, >>> >>> I recently port a ARM926EJ-S mach to Xenomai >>> (like described in http://www.xenomai.org/index.php/I-pipe:ArmPorting). >>> >>> While testing with latency I got this output: >>> # /usr/xenomai/bin/latency -p 1000 -h -s -H 500 -t 1 >>> == Sampling period: 1000 us >>> == Test mode: in-kernel periodic task >>> == All results in microseconds >>> warming up... >>> RTT| 00:00:01 (in-kernel periodic task, 1000 us period, priority 99) >>> RTH|-----lat min|-----lat avg|-----lat max|-overrun|----lat best|---lat worst >>> RTD| 78.992| 104.308| 124.131| 0| 78.992| 124.131 >>> ... >>> RTD| 14.678| 68.413| 96.275| 0| 9.528| 155.321 >>> RTD| 84.046| 116.435| 175.192| 0| 9.528| 182.139 >>> ... ^^^^^^^ ^^^^^^^ >> I do not understand, what is wrong with these values ? > > It thought, if "lat max" of the current interval is bigger than "lat worst", this "lat > max" updates the "lat worst". So I ask myself, out of which interval comes the updated 182 > value? Ok. Got it. What type of floats are you compiling with ? -- Gilles. ^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: [Xenomai-help] strange latency output (xenomai-2.4.5) 2009-02-10 17:22 ` Georg Gottleuber 2009-02-10 17:21 ` Gilles Chanteperdrix @ 2009-02-10 17:29 ` Gilles Chanteperdrix 2009-02-10 17:46 ` Georg Gottleuber 1 sibling, 1 reply; 8+ messages in thread From: Gilles Chanteperdrix @ 2009-02-10 17:29 UTC (permalink / raw) To: Georg Gottleuber; +Cc: xenomai Georg Gottleuber wrote: > > Gilles Chanteperdrix schrieb: >> Georg Gottleuber wrote: >>> Hi, >>> >>> I recently port a ARM926EJ-S mach to Xenomai >>> (like described in http://www.xenomai.org/index.php/I-pipe:ArmPorting). >>> >>> While testing with latency I got this output: >>> # /usr/xenomai/bin/latency -p 1000 -h -s -H 500 -t 1 >>> == Sampling period: 1000 us >>> == Test mode: in-kernel periodic task >>> == All results in microseconds >>> warming up... >>> RTT| 00:00:01 (in-kernel periodic task, 1000 us period, priority 99) >>> RTH|-----lat min|-----lat avg|-----lat max|-overrun|----lat best|---lat worst >>> RTD| 78.992| 104.308| 124.131| 0| 78.992| 124.131 >>> ... >>> RTD| 14.678| 68.413| 96.275| 0| 9.528| 155.321 >>> RTD| 84.046| 116.435| 175.192| 0| 9.528| 182.139 >>> ... ^^^^^^^ ^^^^^^^ >> I do not understand, what is wrong with these values ? > > It thought, if "lat max" of the current interval is bigger than "lat worst", this "lat > max" updates the "lat worst". So I ask myself, out of which interval comes the updated 182 > value? If your machine is highly loaded, like what you get with a ping -f, the "display" thread, which is a non real-time one, may be delayed for more than one second, in which case, it "misses", what is sent by the "sampling" thread, but the sampling thread never looses the worst latency itself, so that when the display thread finally manages to print something, it will print the correct worst case latency. -- Gilles. ^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: [Xenomai-help] strange latency output (xenomai-2.4.5) 2009-02-10 17:29 ` Gilles Chanteperdrix @ 2009-02-10 17:46 ` Georg Gottleuber 2009-02-10 19:16 ` Gilles Chanteperdrix 0 siblings, 1 reply; 8+ messages in thread From: Georg Gottleuber @ 2009-02-10 17:46 UTC (permalink / raw) To: xenomai Gilles Chanteperdrix schrieb: > Georg Gottleuber wrote: >> Gilles Chanteperdrix schrieb: >>> Georg Gottleuber wrote: >>>> Hi, >>>> >>>> I recently port a ARM926EJ-S mach to Xenomai >>>> (like described in http://www.xenomai.org/index.php/I-pipe:ArmPorting). >>>> >>>> While testing with latency I got this output: >>>> # /usr/xenomai/bin/latency -p 1000 -h -s -H 500 -t 1 >>>> == Sampling period: 1000 us >>>> == Test mode: in-kernel periodic task >>>> == All results in microseconds >>>> warming up... >>>> RTT| 00:00:01 (in-kernel periodic task, 1000 us period, priority 99) >>>> RTH|-----lat min|-----lat avg|-----lat max|-overrun|----lat best|---lat worst >>>> RTD| 78.992| 104.308| 124.131| 0| 78.992| 124.131 >>>> ... >>>> RTD| 14.678| 68.413| 96.275| 0| 9.528| 155.321 >>>> RTD| 84.046| 116.435| 175.192| 0| 9.528| 182.139 >>>> ... ^^^^^^^ ^^^^^^^ >>> I do not understand, what is wrong with these values ? >> It thought, if "lat max" of the current interval is bigger than "lat worst", this "lat >> max" updates the "lat worst". So I ask myself, out of which interval comes the updated 182 >> value? > > If your machine is highly loaded, like what you get with a ping -f, the > "display" thread, which is a non real-time one, may be delayed for more > than one second, in which case, it "misses", what is sent by the > "sampling" thread, but the sampling thread never looses the worst > latency itself, so that when the display thread finally manages to print > something, it will print the correct worst case latency. > Bingo. That's the point. This also explains totally equal lines and missing time stamps/lines that I have observed. Thanks a lot. ^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: [Xenomai-help] strange latency output (xenomai-2.4.5) 2009-02-10 17:46 ` Georg Gottleuber @ 2009-02-10 19:16 ` Gilles Chanteperdrix 2009-02-10 19:46 ` Georg Gottleuber 0 siblings, 1 reply; 8+ messages in thread From: Gilles Chanteperdrix @ 2009-02-10 19:16 UTC (permalink / raw) To: Georg Gottleuber; +Cc: xenomai Georg Gottleuber wrote: > > Gilles Chanteperdrix schrieb: >> Georg Gottleuber wrote: >>> Gilles Chanteperdrix schrieb: >>>> Georg Gottleuber wrote: >>>>> Hi, >>>>> >>>>> I recently port a ARM926EJ-S mach to Xenomai >>>>> (like described in http://www.xenomai.org/index.php/I-pipe:ArmPorting). >>>>> >>>>> While testing with latency I got this output: >>>>> # /usr/xenomai/bin/latency -p 1000 -h -s -H 500 -t 1 >>>>> == Sampling period: 1000 us >>>>> == Test mode: in-kernel periodic task >>>>> == All results in microseconds >>>>> warming up... >>>>> RTT| 00:00:01 (in-kernel periodic task, 1000 us period, priority 99) >>>>> RTH|-----lat min|-----lat avg|-----lat max|-overrun|----lat best|---lat worst >>>>> RTD| 78.992| 104.308| 124.131| 0| 78.992| 124.131 >>>>> ... >>>>> RTD| 14.678| 68.413| 96.275| 0| 9.528| 155.321 >>>>> RTD| 84.046| 116.435| 175.192| 0| 9.528| 182.139 >>>>> ... ^^^^^^^ ^^^^^^^ >>>> I do not understand, what is wrong with these values ? >>> It thought, if "lat max" of the current interval is bigger than "lat worst", this "lat >>> max" updates the "lat worst". So I ask myself, out of which interval comes the updated 182 >>> value? >> If your machine is highly loaded, like what you get with a ping -f, the >> "display" thread, which is a non real-time one, may be delayed for more >> than one second, in which case, it "misses", what is sent by the >> "sampling" thread, but the sampling thread never looses the worst >> latency itself, so that when the display thread finally manages to print >> something, it will print the correct worst case latency. >> > > Bingo. That's the point. This also explains totally equal lines and missing time > stamps/lines that I have observed. Yes, the communication between the sampling and display threads is a semaphore, so when the display thread is delayed, it will get the semaphore several times in a row and print the same values. If your patch is for a machine in the mainline linux, I would be happy to merge your changes into the I-pipe patch. It would be interesting if you could try a recent patch with the "FCSE" option, to see if it works for 926 (it was tested for 920 and xscale only), and what gains you get on latencies. -- Gilles. ^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: [Xenomai-help] strange latency output (xenomai-2.4.5) 2009-02-10 19:16 ` Gilles Chanteperdrix @ 2009-02-10 19:46 ` Georg Gottleuber 0 siblings, 0 replies; 8+ messages in thread From: Georg Gottleuber @ 2009-02-10 19:46 UTC (permalink / raw) To: xenomai Gilles Chanteperdrix schrieb: > Georg Gottleuber wrote: >> Gilles Chanteperdrix schrieb: >>> Georg Gottleuber wrote: >>>> Gilles Chanteperdrix schrieb: >>>>> Georg Gottleuber wrote: >>>>>> Hi, >>>>>> >>>>>> I recently port a ARM926EJ-S mach to Xenomai >>>>>> (like described in http://www.xenomai.org/index.php/I-pipe:ArmPorting). >>>>>> >>>>>> While testing with latency I got this output: >>>>>> # /usr/xenomai/bin/latency -p 1000 -h -s -H 500 -t 1 >>>>>> == Sampling period: 1000 us >>>>>> == Test mode: in-kernel periodic task >>>>>> == All results in microseconds >>>>>> warming up... >>>>>> RTT| 00:00:01 (in-kernel periodic task, 1000 us period, priority 99) >>>>>> RTH|-----lat min|-----lat avg|-----lat max|-overrun|----lat best|---lat worst >>>>>> RTD| 78.992| 104.308| 124.131| 0| 78.992| 124.131 >>>>>> ... >>>>>> RTD| 14.678| 68.413| 96.275| 0| 9.528| 155.321 >>>>>> RTD| 84.046| 116.435| 175.192| 0| 9.528| 182.139 >>>>>> ... ^^^^^^^ ^^^^^^^ >>>>> I do not understand, what is wrong with these values ? >>>> It thought, if "lat max" of the current interval is bigger than "lat worst", this "lat >>>> max" updates the "lat worst". So I ask myself, out of which interval comes the updated 182 >>>> value? >>> If your machine is highly loaded, like what you get with a ping -f, the >>> "display" thread, which is a non real-time one, may be delayed for more >>> than one second, in which case, it "misses", what is sent by the >>> "sampling" thread, but the sampling thread never looses the worst >>> latency itself, so that when the display thread finally manages to print >>> something, it will print the correct worst case latency. >>> >> Bingo. That's the point. This also explains totally equal lines and missing time >> stamps/lines that I have observed. > > Yes, the communication between the sampling and display threads is a > semaphore, so when the display thread is delayed, it will get the > semaphore several times in a row and print the same values. > > If your patch is for a machine in the mainline linux, I would be happy > to merge your changes into the I-pipe patch. The merge to mainline is in progress (look for PNX8181). ^ permalink raw reply [flat|nested] 8+ messages in thread
end of thread, other threads:[~2009-02-10 19:46 UTC | newest] Thread overview: 8+ messages (download: mbox.gz follow: Atom feed -- links below jump to the message on this page -- 2009-02-10 16:49 [Xenomai-help] strange latency output (xenomai-2.4.5) Georg Gottleuber 2009-02-10 16:47 ` Gilles Chanteperdrix 2009-02-10 17:22 ` Georg Gottleuber 2009-02-10 17:21 ` Gilles Chanteperdrix 2009-02-10 17:29 ` Gilles Chanteperdrix 2009-02-10 17:46 ` Georg Gottleuber 2009-02-10 19:16 ` Gilles Chanteperdrix 2009-02-10 19:46 ` Georg Gottleuber
This is an external index of several public inboxes, see mirroring instructions on how to clone and mirror all data and code used by this external index.