Fwd: Timer overshooting consistently.

I'm forwarding this email back to Orocos-users because I accidentally
replied straight back to Markus Klotzbuecher instead of the list.

> Are you running on Xenomai or RT_PREEMPT and setting real-time
> priorities? If yes, I would try to directly use POSIX clock_nanosleep
> with CLOCK_MONOTONIC and sleep to an absolute time. If that solves the
> problem, it's something to do with RTT::os::Timer...
>
> Markus

RT_PREEMPT (w/ full preemption) and yes, we are at a realtime
priority. Prior to implementing my code via Orocos, I was using
clock_nanosleep with success.

As best as I can tell, the only thing it could be other than
RTT::os::Timer is the TimeService -- perhaps the way I'm reading the
time is unreasonable slow? In case this is it, here is my timekeeping
code:

void ECatComm::timeout(TimerId timer_id) {
RTT::os::TimeService::nsecs overshoot =
RTT::os::TimeService::Instance()->getNSecs() - targetTime;
// overshoot is about 60000 ns here.
RTT::os::TimeService::nsecs sleepTime;

/* Code does stuff here, calculates sleepTime */

targetTime = sleepTime + RTT::os::TimeService::Instance()->getNSecs();
arm(timer_id, ((double) sleepTime) / 1000000000.0);
}

Am I reading the time incorrectly? Perhaps my way of using TimeService
is actually taking the 60 µs, and that the timer isn't actually
overshooting by as much as I thought.

Thank you,
Johnathan Van Why
Dynamic Robotics Laboratory
Oregon State University

Timer overshooting consistently.

On Jul 31, 2012, at 14:55 , Johnathan Van Why wrote:

> I'm forwarding this email back to Orocos-users because I accidentally
> replied straight back to Markus Klotzbuecher instead of the list.
>
>> Are you running on Xenomai or RT_PREEMPT and setting real-time
>> priorities? If yes, I would try to directly use POSIX clock_nanosleep
>> with CLOCK_MONOTONIC and sleep to an absolute time. If that solves the
>> problem, it's something to do with RTT::os::Timer...
>>
>> Markus
>
> RT_PREEMPT (w/ full preemption) and yes, we are at a realtime
> priority. Prior to implementing my code via Orocos, I was using
> clock_nanosleep with success.
>
> As best as I can tell, the only thing it could be other than
> RTT::os::Timer is the TimeService -- perhaps the way I'm reading the
> time is unreasonable slow? In case this is it, here is my timekeeping
> code:

Benchmark "RTT::os::TimeService::Instance()->getNSecs()" and see much of your 60us that takes.

What overshoot would be good enough? I agree with Markus ... if you need better accuracy, try clock_nanosleep as proposed. That's how RTT and many other systems do it.
S

>
> void ECatComm::timeout(TimerId timer_id) {
> RTT::os::TimeService::nsecs overshoot =
> RTT::os::TimeService::Instance()->getNSecs() - targetTime;
> // overshoot is about 60000 ns here.
> RTT::os::TimeService::nsecs sleepTime;
>
> /* Code does stuff here, calculates sleepTime */
>
> targetTime = sleepTime + RTT::os::TimeService::Instance()->getNSecs();
> arm(timer_id, ((double) sleepTime) / 1000000000.0);
> }
>
> Am I reading the time incorrectly? Perhaps my way of using TimeService
> is actually taking the 60 µs, and that the timer isn't actually
> overshooting by as much as I thought.

Timer overshooting consistently.

Hi,

On Tue, Jul 31, 2012 at 07:26:56PM -0400, S Roderick wrote:
> On Jul 31, 2012, at 14:55 , Johnathan Van Why wrote:
>
> > I'm forwarding this email back to Orocos-users because I accidentally
> > replied straight back to Markus Klotzbuecher instead of the list.
> >
> >> Are you running on Xenomai or RT_PREEMPT and setting real-time
> >> priorities? If yes, I would try to directly use POSIX clock_nanosleep
> >> with CLOCK_MONOTONIC and sleep to an absolute time. If that solves the
> >> problem, it's something to do with RTT::os::Timer...
> >>
> >> Markus
> >
> > RT_PREEMPT (w/ full preemption) and yes, we are at a realtime
> > priority. Prior to implementing my code via Orocos, I was using
> > clock_nanosleep with success.
> >
> > As best as I can tell, the only thing it could be other than
> > RTT::os::Timer is the TimeService -- perhaps the way I'm reading the
> > time is unreasonable slow? In case this is it, here is my timekeeping
> > code:
>
> Benchmark "RTT::os::TimeService::Instance()->getNSecs()" and see much of your 60us that takes.
>
> What overshoot would be good enough? I agree with Markus ... if you
> need better accuracy, try clock_nanosleep as proposed. That's how
> RTT and many other systems do it.

I agree. (I would even argue that POSIX (or a subset thereof) should
*be* RTT's FOSI layer, and replace RTT's yet another glue layer).

> > void ECatComm::timeout(TimerId timer_id) {
> > RTT::os::TimeService::nsecs overshoot =
> > RTT::os::TimeService::Instance()->getNSecs() - targetTime;
> > // overshoot is about 60000 ns here.
> > RTT::os::TimeService::nsecs sleepTime;
> >
> > /* Code does stuff here, calculates sleepTime */
> >
> > targetTime = sleepTime + RTT::os::TimeService::Instance()->getNSecs();
> > arm(timer_id, ((double) sleepTime) / 1000000000.0);

BTW, this conversion to double seconds, which is then probably
converted back to nsec's in the Timer code looks numerically
fishy. Could the problem be caused by rounding errors?

Markus

Timer overshooting consistently.

> BTW, this conversion to double seconds, which is then probably
> converted back to nsec's in the Timer code looks numerically
> fishy. Could the problem be caused by rounding errors?

I find it a bit fishy too... but rounding errors are not an issue (I
just confirmed this with some printf's).

The reason I like to use Orocos's Timer class is one of thread safety.
This component (which we call our Realtime Operations component) not
only runs cyclicly, but also has operations that are called by other
components. Making this entire component threadsafe would be a
nightmare (I'd more or less need one lock for the entire thing).
However, if my understanding is correct (please correct me if I am
wrong), everything run under the "ORO_SCHED_RT" scheduler occurs in
one thread, automatically solving my thread safety issues.

Using the Timer class allows me to easily run my code in this thread.
The alternative is to spawn off a thread just for timing, and have
that thread trigger execution of the main thread... I haven't tested
this, but that may still have the 60µs latency.

The interesting thing is how consistent the timing is. It isn't very
jittery (it's almost always within the 60-70µs range), but I will
occasionally see much smaller overshoots (like 30µs or less). This
seems to happen less than 1% of the time... but 1% of the time is
still quite significant.

I'm still not sure where exactly the problem lies. Although I don't
think that we are running anything in a RT priority at the moment this
thread wakes up, I also wouldn't expect RTT::os::Timer to overshoot
with this pattern of consistency (i.e. 99% but not 100% of the time).
That being said, it's so consistent that we can simply compensate for
the overshoot without much trouble.

Thank you for your help,
Johnathan Van Why
Dynamic Robotics Laboratory
Oregon State University

Timer overshooting consistently.

> Benchmark "RTT::os::TimeService::Instance()->getNSecs()" and see much of your 60us that takes.

We've benchmarked "RTT::os::TimeService::Instance()->getNSecs()" and
it takes around 60ns, so it's not the problem.

For now, we're simply calculating the overshoot (which is fairly
consistent) and using a while() loop to verify it didn't undershoot
(which occasionally occurs). I believe this is preferable to doing
timing ourselves, due to threading concerns.

Thank you for responding,
Johnathan Van Why
Dynamic Robotics Laboratory
Oregon State University