Re: Vulcano Test

On 04/01/2016 09:50 AM, Felix Frey wrote:
> I agree that caching influence cannot explain these large differences.
> If this would be the case then calibrating wouldn't make sense.
>
> However, I did some more testing on other machines:
> On a elderly AMD Athlon II (dual core) and on a modern i7 (actually quad
> core but set to dual core in Bios).
> On both manchines I get very similar results. I tested only with a
> period of 200000ns and the calibration values were between 10000 and
> 30000. The i7 even showed much higher KernelLatency than UserLatency.
>
> All these values doesn't really make sense to me, however, so far I
> don't have an idea about the reason.
>
> Could it be an issue of kernel configuration?
> (I started with a x86_64 default config and disabled everything I don't
> need)
There maybe the need of tuning options related to what is kept 
configured, e.g. idle cpu options, on the fly change of cpu frequency, 
ACPI options, which could affect the tuning/checking phase. In fact 
during the related time we often work with a calm machine and at a low 
frequency the system maybe tempted to save power.
In such a view I must say that my machines are old enough to be 
vaccinated against such issues. It is a fact that I've often found newer 
architectures less suitable for a ready real time use than older one, 
requiring more tuning tweaks.

I hope to have some feedback more from RTAI users.

Paolo

> Felix
>
> Am 01.04.2016 um 09:29 schrieb Paolo Mantegazza:
>> Ciao,
>>
>> I'm returning to this thread because I would like to learn something more.
>> The caching issue we have discussed makes sense, but the figures you
>> presented, in my experience at least,
>> are a "bit" higher than expected.
>> Just as an example I've calibrated at 1 and 10 KHz, for which you got:
>>
>> Period=100000 -> KernelLatency 4522, UserLatency 5042
>> Period=1000000 -> KernelLatency 35829, UserLatency 48231 while I had:
>>
>> while I have:
>>
>> Period=100000 -> KernelLatency 1851, UserLatency 2599
>> Period=1000000 -> KernelLatency 2450, UserLatency 3239
>>
>> The cache effect can be seen but is not almost as 10 times higher as is
>> yours.
>>
>> My results are for a 2 SMP, P III, 1 GHz. Nonetheless their ratio is
>> similar to the one I get
>> on a 3 GHz dual core Pentium.
>>
>> Do you have any idea of the reason why you hardware is so lazy in
>> caching? It would be clearly interesting to see other results from
>> different user/hardware.
>>
>> Paolo
>>
>> On 03/31/2016 06:44 PM, Paolo Mantegazza wrote:
>>> Period=20000  ->  KernelLatency 4551, UserLatency 5104
>>> Period=50000  ->  KernelLatency 4443, UserLatency 4760
>>> Period=100000 ->  KernelLatency 4522, UserLatency 5042
>>> Period=200000 ->  KernelLatency 20973, UserLatency 23225
>>> Period=1000000 -> KernelLatency 35829, UserLatency 48231
>>> Period=2000000 -> KernelLatency 87183, UserLatency 110500
>>>
>>> The results above are OK. They just confirm the following statement of
>>> the config helper:
>>> "...  Use a period that is closer to your range of interest. Because of
>>>           cache warming, lower periods will tend to anticipate the
>>> scheduling
>>>           when higher ones are used and viceversa. ..."
>>> I find it interesting to see that your machine is much more sensitive
>>> to caching issues than mine, despite a  roughly
>>> equivalent hardware, in terms of CPU and lapic freq at least.
>>> In fact what happened to you before was that your calibrated with the
>>> default period, 200000, then tested with
>>> half of it, i.e. 100000. From your data above an anticipation of
>>> (23225 - 5042) had to be expected. It is not exactly so, because
>>> the calibrating and latency test are somewhat different, but the order
>>> of magnitude is that.
>>>
>>> What is important for me is that you are confirming that there is no
>>> need of a long calibration, something that matches my experience.
>>> Maybe the figures above could be mended somewhat, by a longer warming
>>> up of the cache, but is a fact that  low frequency
>>> tasks may have a (significantly) higher latency.
>>>
>>> So there is little that RTAI can do to substitute a user's judgment.
>>> While waiting for further checks I'll decrease the  default
>>> calibration period
>>> the one used for the installed latency examples.
>>>
>>> On the other hand, since the calibration is based on assuring a null
>>> average, the negative infimum extremes are somewhat expected.
>>>
>>> In any case I think that the added possibility of setting more
>>> valuable available values either  in the latencies file or through
>>> modules parameters,
>>> without the need of reconfiguring and remaking, should make things
>>> easier.
>>>
>>> Many thanks for your useful help and checks, Paolo.
>>>
>>> ________________________________________
>>> From: Rtai [[email protected]] on behalf of Felix Frey
>>> [[email protected]]
>>> Sent: Thursday, March 31, 2016 4:49 PM
>>> To: [email protected]
>>> Subject: Re: [Rtai] Vulcano Test
>>>
>>> Updated CVS and test again.
>>>
>>> So far, I get the same results.
>>>
>>> When I put your calibration values (1715/2225) in my latencies file then
>>> I get much more reasonable latency values:
>>>
>>> RTAI Testsuite - USER latency (all data in nanoseconds)
>>> 2016/03/31 15:10:22
>>> RTH| lat min| ovl min| lat avg| lat max| ovl max| overruns
>>> RTD| 1110| 1110| 3643| 7019| 7019| 0
>>> RTD| 2500| 1110| 3671| 5681| 7019| 0
>>> RTD| 1749| 1110| 3664| 6475| 7019| 0
>>> RTD| 1906| 1110| 3657| 6631| 7019| 0
>>>
>>>
>>> Now I played with the period and time values. The latter one has no
>>> influence, however, the effect of the period value is interesting
>>> and not expected, I think:
>>>
>>> Period=20000  ->  KernelLatency 4551, UserLatency 5104
>>> Period=50000  ->  KernelLatency 4443, UserLatency 4760
>>> Period=100000 ->  KernelLatency 4522, UserLatency 5042
>>> Period=200000 ->  KernelLatency 20973, UserLatency 23225
>>> Period=1000000 -> KernelLatency 35829, UserLatency 48231
>>> Period=2000000 -> KernelLatency 87183, UserLatency 110500
>>>
>>> Putting the values of the 1st line (4551/5104) into the latencies file
>>> still produces negative latencies:
>>>
>>> RTAI Testsuite - USER latency (all data in nanoseconds)
>>> 2016/03/31 15:42:22
>>> RTH| lat min| ovl min| lat avg| lat max| ovl max| overruns
>>> RTD| -1468| -1468| 781| 3692| 3692| 0
>>> RTD| -1362| -1468| 769| 2432| 3692| 0
>>> RTD| -1529| -1529| 777| 3602| 3692| 0
>>> RTD| -1398| -1529| 765| 3000| 3692| 0
>>>
>>>
>>> By the way, when I changed the time value to 5s, the output remains like
>>> this (TIME is wrong):
>>>
>>> AFTER USER CALIBRATION (ns): KernelLatency 4568, UserLatency 5060
>>> (CALIBRATION: PERIOD 100000 (ns), TIME 1015577174 (ns)).
>>>
>>>
>>> attached my rtai_config.h
>>>
>>> Felix
>>>
>>>
>>> Am 31.03.2016 um 15:39 schrieb Paolo Mantegazza:
>>>> That's (calibration) something really strange. Just wondering why on a
>>>> machine like yours I get:
>>>> SYSINFO - # CPUs: 2, TIMER NAME: 'lapic', TIMER IRQ: 2305, TIMER FREQ:
>>>> 8308369,
>>>> CLOCK NAME: 'tsc', CLOCK FREQ: 997204000, CPU FREQ: 997204000, LINUX
>>>> TIMER IRQ:
>>>> 2305.
>>>> RTAI[malloc]: global heap size = 2097152 bytes, <TLSF>.
>>>> , kstacks pool size = 524288 bytes.
>>>> RTAI[sched]: hard timer type/freq = lapic/8308369(Hz); timing: oneshot;
>>>> black/red timed lists.
>>>> RTAI[sched]: Linux timer freq = 1000 (Hz), TimeBase freq = 997204000 hz.
>>>> RTAI[sched]: timer setup = 120 ns, resched latency = 0 ns.
>>>> RTAI[usi]: enabled.
>>>> USERMODE CHECK: OK.
>>>> USERMODE CHECK PROVIDED (ns): KernelLatency -1, UserLatency -1.
>>>> AFTER KERNEL CALIBRATION (WITH RTAI TASK, ns): KernelLatency 1715,
>>>> UserLatency -1 (CALIBRATION: PERIOD 100000 (ns), TIME 1009367042 (ns)).
>>>> USERMODE USER SPACE CALIBRATION: OK.
>>>> AFTER USER CALIBRATION (ns): KernelLatency 1715, UserLatency 2225
>>>> (CALIBRATION:
>>>> vi list    PERIOD 100000 (ns), TIME 1014464466 (ns)).
>>>> FINAL CALIBRATION SUMMARY (ns): KernelLatency 1715, UserLatency 2225.
>>>>
>>>> with
>>>>
>>>> RTAI Testsuite - USER latency (all data in nanoseconds)
>>>> 2016/03/31 15:32:32
>>>> RTH|    lat min|    ovl min|    lat avg|    lat max|    ovl max|
>>>> overruns
>>>> RTD|        121|        121|        609|       6424| 6424|          0
>>>> RTD|        434|        121|        548|       3984| 6424|          0
>>>> ^CRTD|        434|        121|        548|       3984| 6424|          0
>>>>
>>>>>>> S = 98.696, EXECTIME = 0.0325566
>>>> Since I've consistent results on two other machines, up to 3.3 GHz, I'm
>>>> let asking you to help me in seeing what goes wrong.
>>>> In such a view edits "latencies" file, found in subdir calibrate of your
>>>> installation directory, putting my figures above in it and checking what
>>>> you get with the test.
>>>> Then you can play configuring with the period and calibration duration
>>>> to see if they provide a change, and report the outcomes.
>>>> BTW, send me the rtai_config.h that produced those results.
>>>>
>>>> Paolo
>>>>
>>>> On 03/31/2016 03:15 PM, Felix Frey wrote:
>>>>> Just tested vulcano CVS with kernel 4.1.18
>>>>> (on AMD GX-210, x86_64, 2 cores)
>>>>>
>>>>> Running userspace latency test gives:
>>>>>
>>>>> RTAI Testsuite - USER latency (all data in nanoseconds)
>>>>> 2016/03/31 14:02:43
>>>>> RTH| lat min| ovl min| lat avg| lat max| ovl max| overruns
>>>>> RTD| -19935| -19935| -18063| -14615| -14615| 0
>>>>> RTD| -19723| -19935| -18050| -15267| -14615| 0
>>>>> RTD| -19514| -19935| -18060| -15083| -14615| 0
>>>>> RTD| -20177| -20177| -18063| -15137| -14615| 0
>>>>> RTD| -19828| -20177| -18060| -15116| -14615| 0
>>>>>
>>>>> These are the kernel messages:
>>>>>
>>>>> [ 1319.188664] RTAI[hal]: mounted. ISOL_CPUS_MASK: 0, LINUX CPU
>>>>> ISOLATED
>>>>> MAP: ffffffff81e61c20).
>>>>> [ 1319.197214] SYSINFO - # CPUs: 2, TIMER NAME: 'lapic', TIMER IRQ:
>>>>> 4353, TIMER FREQ: 6238209, CLOCK NAME: 'tsc', CLOCK FREQ: 998088000, CP
>>>>> U FREQ: 998088000, LINUX TIMER IRQ: 4353.
>>>>> [ 1319.248508] RTAI[malloc]: global heap size = 2097152 bytes, <BSD>.
>>>>> [ 1319.254814] , kstacks pool size = 524288 bytes.
>>>>> [ 1319.259457] RTAI[sched]: hard timer type/freq = lapic/6238209(Hz);
>>>>> timing: oneshot; linear timed lists.
>>>>> [ 1319.268913] RTAI[sched]: Linux timer freq = 250 (Hz), TimeBase
>>>>> freq =
>>>>> 998088000 hz.
>>>>> [ 1319.276593] RTAI[sched]: timer setup = 160 ns, resched latency =
>>>>> 0 ns.
>>>>> [ 1319.284973] USERMODE CHECK: OK.
>>>>> [ 1319.288155] USERMODE CHECK PROVIDED (ns): KernelLatency -1,
>>>>> UserLatency -1.
>>>>> [ 1320.331572] AFTER KERNEL CALIBRATION (WITH RTAI TASK, ns):
>>>>> KernelLatency 21009, UserLatency -1 (CALIBRATION: PERIOD 200000 (ns),
>>>>> TIME 10
>>>>> 36380956 (ns)).
>>>>> [ 1321.362282] USERMODE USER SPACE CALIBRATION: OK.
>>>>> [ 1321.366937] AFTER USER CALIBRATION (ns): KernelLatency 21009,
>>>>> UserLatency 23941 (CALIBRATION: PERIOD 200000 (ns), TIME 1021744803
>>>>> (ns)).
>>>>> [ 1321.379211] FINAL CALIBRATION SUMMARY (ns): KernelLatency 21009,
>>>>> UserLatency 23941.
>>>>> [ 1334.500839] RTAI[malloc]: unloaded.
>>>>> [ 1334.600674] RTAI[sched]: unloaded (forced hard/soft/hard
>>>>> transitions:
>>>>> traps 0, syscalls 0).
>>>>> [ 1334.623217] I-pipe: head domain RTAI unregistered.
>>>>> [ 1334.628084] RTAI[hal]: unmounted.
>>>>>
>>>>>
>>>>> The latency values are probably not what they are expected to.
>>>>> In my opinion the calibration delivers much too high values
>>>>> (21009/23941).
>>>>> Any ideas??
>>>>>
>>>>> Felix
>>>>>
>>>>> _______________________________________________
>>>>> Rtai mailing list
>>>>> [email protected]
>>>>> https://mail.rtai.org/cgi-bin/mailman/listinfo/rtai
>>>> _______________________________________________
>>>> Rtai mailing list
>>>> [email protected]
>>>> https://mail.rtai.org/cgi-bin/mailman/listinfo/rtai
>>>>
>>> _______________________________________________
>>> Rtai mailing list
>>> [email protected]
>>> https://mail.rtai.org/cgi-bin/mailman/listinfo/rtai

_______________________________________________
Rtai mailing list
[email protected]
https://mail.rtai.org/cgi-bin/mailman/listinfo/rtai