From: Gilles Chanteperdrix <gilles.chanteperdrix@xenomai.org>
To: Jeroen Van den Keybus <jeroen.vandenkeybus@gmail.com>
Cc: "xenomai@xenomai.org" <xenomai@xenomai.org>
Subject: Re: [Xenomai] Reading /proc/xenomai/stat causes high latencies
Date: Wed, 10 Sep 2014 21:47:34 +0200 [thread overview]
Message-ID: <5410AAD6.3050808@xenomai.org> (raw)
In-Reply-To: <CAPRPZsCHZKW8kpGgacM3dtiF9UOU5+PsHP=L+L_ZMM1YbYWPxQ@mail.gmail.com>
On 09/10/2014 03:50 PM, Jeroen Van den Keybus wrote:
> Hi Gilles,
>
>
>
>> Answering with a "little" delay, could you try the following patch?
>>
>
> No problem. And we understand you are busy.
>
> The tests below consist of running ./latency at 10 kHz and continuously
> open, read and close /proc/xenomai/stat. We can read at about 200 Hz. We
> let it cook for 10 minutes.
>
> To verify, we tested again without the patch (problems after one sec
> already, so we stopped this):
>
> == Sampling period: 100 us
>
> == Test mode: periodic user-mode task
>
> == All results in microseconds
>
> warming up...
>
> RTT| 00:00:01 (periodic user-mode task, 100 us period, priority 99)
>
> RTH|----lat min|----lat avg|----lat max|-overrun|---msw|---lat best|--lat
> worst
>
> RTD| 0.725| 0.956| 1.524| 0| 0| 0.725|
> 1.524
>
> RTD| 0.782| 0.936| 1.482| 0| 0| 0.725|
> 1.524
>
> RTD| 0.886| 0.936| 1.750| 0| 0| 0.725|
> 1.750
>
> RTD| 0.886| 2.355| 546.854| 5| 0| 0.725|
> 546.854
>
> RTD| 1.253| 4.380| 629.025| 15| 0| 0.725|
> 629.025
>
> RTD| 1.292| 4.348| 578.529| 19| 0| 0.725|
> 629.025
>
> RTD| 1.287| 4.375| 662.344| 27| 0| 0.725|
> 662.344
>
> RTD| 1.265| 4.372| 369.331| 35| 0| 0.725|
> 662.344
>
>
> And with the patch (same conditions for 10 minutes):
>
> RTH|----lat min|----lat avg|----lat max|-overrun|---msw|---lat best|--lat
> worst
>
> RTD| 1.152| 1.230| 1.889| 0| 0| 0.547|
> 2.591
>
> RTD| 1.054| 1.231| 1.824| 0| 0| 0.547|
> 2.591
>
> RTD| 1.148| 1.229| 1.775| 0| 0| 0.547|
> 2.591
>
> RTD| 1.057| 1.231| 1.782| 0| 0| 0.547|
> 2.591
>
> RTD| 1.150| 1.231| 1.786| 0| 0| 0.547|
> 2.591
>
> RTD| 1.045| 1.230| 1.888| 0| 0| 0.547|
> 2.591
>
> RTD| 1.151| 1.231| 1.761| 0| 0| 0.547|
> 2.591
>
> RTD| 0.999| 1.230| 2.049| 0| 0| 0.547|
> 2.591
>
> RTD| 1.148| 1.231| 1.818| 0| 0| 0.547|
> 2.591
>
> RTD| 1.031| 1.231| 1.784| 0| 0| 0.547|
> 2.591
>
> RTD| 1.149| 1.231| 1.818| 0| 0| 0.547|
> 2.591
>
> RTD| 0.832| 1.228| 1.976| 0| 0| 0.547|
> 2.591
>
> RTD| 1.149| 1.226| 1.805| 0| 0| 0.547|
> 2.591
>
> RTD| 1.025| 1.225| 1.842| 0| 0| 0.547|
> 2.591
>
> RTD| 1.150| 1.225| 1.795| 0| 0| 0.547|
> 2.591
>
> RTD| 1.053| 1.225| 1.774| 0| 0| 0.547|
> 2.591
>
> RTD| 1.150| 1.226| 1.876| 0| 0| 0.547|
> 2.591
>
> RTD| 0.910| 1.225| 2.205| 0| 0| 0.547|
> 2.591
>
> RTD| 1.149| 1.225| 1.819| 0| 0| 0.547|
> 2.591
>
> RTD| 0.716| 1.225| 1.774| 0| 0| 0.547|
> 2.591
>
> RTD| 0.873| 1.225| 1.925| 0| 0| 0.547|
> 2.591
>
> RTT| 00:09:49 (periodic user-mode task, 100 us period, priority 99)
>
>
>
> We also checked the kernel performance without reading stat:
>
> RTH|----lat min|----lat avg|----lat max|-overrun|---msw|---lat best|--lat
> worst
>
> RTD| 0.906| 0.917| 1.377| 0| 0| 0.494|
> 2.600
>
> RTD| 0.905| 0.916| 1.501| 0| 0| 0.494|
> 2.600
>
> RTD| 0.905| 0.916| 1.357| 0| 0| 0.494|
> 2.600
>
> RTD| 0.905| 0.960| 1.395| 0| 0| 0.494|
> 2.600
>
> RTD| 0.594| 0.916| 1.349| 0| 0| 0.494|
> 2.600
>
> RTD| 0.906| 0.917| 1.364| 0| 0| 0.494|
> 2.600
>
> RTD| 0.905| 0.916| 1.331| 0| 0| 0.494|
> 2.600
>
> RTD| 0.905| 0.917| 1.333| 0| 0| 0.494|
> 2.600
>
> RTD| 0.846| 0.954| 1.363| 0| 0| 0.494|
> 2.600
>
> RTD| 0.906| 0.917| 1.369| 0| 0| 0.494|
> 2.600
>
> RTD| 0.906| 0.917| 1.365| 0| 0| 0.494|
> 2.600
>
> RTD| 0.905| 0.917| 1.341| 0| 0| 0.494|
> 2.600
>
> RTD| 0.906| 0.917| 1.354| 0| 0| 0.494|
> 2.600
>
> RTD| 0.906| 0.957| 1.340| 0| 0| 0.494|
> 2.600
>
> RTD| 0.905| 0.917| 1.380| 0| 0| 0.494|
> 2.600
>
> RTD| 0.905| 0.918| 1.356| 0| 0| 0.494|
> 2.600
>
> RTD| 0.905| 0.917| 1.339| 0| 0| 0.494|
> 2.600
>
> RTD| 0.905| 0.917| 1.331| 0| 0| 0.494|
> 2.600
>
> RTD| 0.906| 0.955| 1.376| 0| 0| 0.494|
> 2.600
>
> RTD| 0.906| 0.917| 1.353| 0| 0| 0.494|
> 2.600
>
> RTD| 0.604| 0.916| 1.379| 0| 0| 0.494|
> 2.600
>
> RTT| 00:10:10 (periodic user-mode task, 100 us period, priority 99)
>
>
>
> You can clearly observe an increase of the average latency (about 300 ns),
> but the worst case latency isn't necessarily worse.
>
> Obviously the patch works. Thanks !
>
> Do I understand correctly that currently a flag (lock) set on one CPU isn't
> observable by another CPU (due to e.g. cache) ?
Currently, freeing the lock is not perceived immediately by the cpus
waiting for the lock, that is because the lock is freed with atomic_set,
which does not contain a barrier. The lock, however, is locked with
atomic_cmpxchg, which is a full barrier, so, there is no way a locked
lock can be perceived as free.
That accountfs for the barriers in xnlock_put and __xnlock_spin. However
these two barriers do not seem to be sufficient to avoid the issue
completely, either busy sleeping in the snapshot code, or putting a
barrier in front of the cmpxchg in the xlock_get code seems to be
necessary. I have chosen the latter, because it has a smaller impact
than the former, but I am not entirely satisfied (busy sleeping is a bit
ugly).
--
Gilles.
next prev parent reply other threads:[~2014-09-10 19:47 UTC|newest]
Thread overview: 40+ messages / expand[flat|nested] mbox.gz Atom feed top
2014-04-22 16:02 [Xenomai] Reading /proc/xenomai/stat causes high latencies Jeroen Van den Keybus
2014-04-23 9:14 ` Jeroen Van den Keybus
2014-04-23 13:45 ` Jeroen Van den Keybus
2014-04-23 14:07 ` Gilles Chanteperdrix
2014-04-23 20:54 ` Jeroen Van den Keybus
2014-04-23 20:56 ` Gilles Chanteperdrix
2014-04-23 21:39 ` Jeroen Van den Keybus
2014-04-23 22:25 ` Gilles Chanteperdrix
2014-04-24 8:57 ` Jeroen Van den Keybus
2014-04-24 14:46 ` Jeroen Van den Keybus
2014-04-25 8:15 ` Jeroen Van den Keybus
2014-04-25 10:44 ` Jeroen Van den Keybus
2014-09-09 21:03 ` Gilles Chanteperdrix
2014-09-10 13:50 ` Jeroen Van den Keybus
2014-09-10 19:47 ` Gilles Chanteperdrix [this message]
2014-09-11 5:11 ` Jan Kiszka
2014-09-11 5:19 ` Jan Kiszka
2014-09-18 11:46 ` Gilles Chanteperdrix
2014-09-18 11:59 ` Jan Kiszka
2014-09-18 12:11 ` Gilles Chanteperdrix
2014-09-18 12:17 ` Gilles Chanteperdrix
2014-09-18 12:20 ` Jan Kiszka
2014-09-18 13:05 ` Gilles Chanteperdrix
2014-09-18 13:26 ` Jan Kiszka
2014-09-18 13:44 ` Gilles Chanteperdrix
2014-09-18 16:14 ` Jan Kiszka
2014-09-18 16:28 ` Gilles Chanteperdrix
2014-09-18 18:39 ` Gilles Chanteperdrix
2014-09-18 19:23 ` Jan Kiszka
2014-09-18 19:31 ` Gilles Chanteperdrix
2014-09-18 19:09 ` Jan Kiszka
2014-09-18 19:32 ` Gilles Chanteperdrix
2014-09-18 19:56 ` Jan Kiszka
2014-09-18 20:13 ` Gilles Chanteperdrix
2014-09-18 20:21 ` Gilles Chanteperdrix
2014-09-19 2:06 ` Gilles Chanteperdrix
2014-09-19 5:41 ` Jan Kiszka
2014-09-19 7:04 ` Philippe Gerum
2014-09-19 10:51 ` Gilles Chanteperdrix
2014-09-16 11:09 ` Gilles Chanteperdrix
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
Avoid top-posting and favor interleaved quoting:
https://en.wikipedia.org/wiki/Posting_style#Interleaved_style
* Reply using the --to, --cc, and --in-reply-to
switches of git-send-email(1):
git send-email \
--in-reply-to=5410AAD6.3050808@xenomai.org \
--to=gilles.chanteperdrix@xenomai.org \
--cc=jeroen.vandenkeybus@gmail.com \
--cc=xenomai@xenomai.org \
/path/to/YOUR_REPLY
https://kernel.org/pub/software/scm/git/docs/git-send-email.html
* If your mail client supports setting the In-Reply-To header
via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line
before the message body.
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.