Fwd: clock_gettime() result going backwards on LEON3?

Tue Jun 23 16:23:31 UTC 2015

That was it.  Our version of ckinit.c doesn't have the bug fix.

Thanks, Joel.   As always, appreciate your support.

We were doing some algorithm timing, and weren't sure whether we could trust the results.  Appears that we can, just knowing that we need to either fix or account for this anomaly happening sometimes.

Scott

--

Scott Miller | 210-522-4249 | Senior Research Engineer | Southwest Research Institute

Begin forwarded message:

From: Joel Sherrill <joel.sherrill at oarcorp.com<mailto:joel.sherrill at oarcorp.com>>
Subject: Re: clock_gettime() result going backwards on LEON3?
Date: June 23, 2015 at 10:06:54 AM CDT
To: "Miller, Scott A." <scott.miller at swri.org<mailto:scott.miller at swri.org>>, "users at rtems.org<mailto:users at rtems.org>" <users at rtems.org<mailto:users at rtems.org>>

On 6/23/2015 9:48 AM, Miller, Scott A. wrote:
It was actually pulled before I joined the project, so I am a bit fuzzy on the details, but I believe October 2013.    It appears to be a download of the RCC from Gaisler.  Here's VERSION:

samiller at buttercup:/project/RTEMS/rtems-4.10$ cat VERSION
RCC-1.1.99.12a. RTEMS-4.10, GCC 4.3.3

There is a PR for that and I think it is fixed on the branch.

The simplest way to check is to clone the repo, check out the branch
and look at the history for leon3/clock/ckinit.c. I suspect the code
in bsp_clock_nanoseconds_since_last_tick() will look different from
what you have. It tracks back to this change:

   2011-03-04  Joel Sherrill <joel.sherrilL at OARcorp.com<mailto:joel.sherrilL at OARcorp.com>>
           PR 1748/bsps
       * clock/ckinit.c, include/leon.h: When the clock tick generates an
       interrupt WHILE we have interrupts disabled doing a get TOD or
       uptime, the get nanoseconds handler was returning a bogusly large
       number.

Assuming what you have is 4.10 plus some patches. It is likely missing this
one.

If that doesn't do it, then either I am guessing the wrong rtems version
or we have a different issue.

Recently 4.11 has had time rework and this code was touched again. So if
you are using the git master, the problem and solution will be different.

Scott

On Jun 23, 2015, at 9:39 AM, Joel Sherrill <Joel.Sherrill at OARcorp.com<mailto:Joel.Sherrill at OARcorp.com>> wrote:

On 6/23/2015 9:11 AM, Miller, Scott A. wrote:
Hello,

I'm observing that intermittently, that two successive calls to clock_gettime() will result in the 2nd timespec result being "before" the 1st timespec result.

Here's the code and some example output showing this:

<code snippet>

#include <rtems.h>
#include <bsp.h>
#define CONFIGURE_INIT

rtems_task Init(rtems_task_argument ignored);

#define CONFIGURE_APPLICATION_NEEDS_CONSOLE_DRIVER
#define CONFIGURE_APPLICATION_NEEDS_CLOCK_DRIVER
#define CONFIGURE_APPLICATION_NEEDS_NULL_DRIVER      1
#define CONFIGURE_INIT_TASK_ATTRIBUTES               RTEMS_FLOATING_POINT
#define CONFIGURE_INIT_TASK_STACK_SIZE               (10 * RTEMS_MINIMUM_STACK_SIZE)
#define CONFIGURE_MAXIMUM_TASKS                      13
#define CONFIGURE_RTEMS_INIT_TASKS_TABLE
#define CONFIGURE_MAXIMUM_DRIVERS                    16
#define CONFIGURE_LIBIO_MAXIMUM_FILE_DESCRIPTORS     32
#define CONFIGURE_EXTRA_TASK_STACKS                  (10 * RTEMS_MINIMUM_STACK_SIZE)
#define CONFIGURE_MAXIMUM_POSIX_MUTEXES              rtems_resource_unlimited(10)
#define CONFIGURE_MAXIMUM_POSIX_CONDITION_VARIABLES  rtems_resource_unlimited(10)
#define CONFIGURE_MAXIMUM_POSIX_SEMAPHORES           rtems_resource_unlimited(10)
#define CONFIGURE_UNIFIED_WORK_AREAS
#include <rtems/confdefs.h>

....

    struct timespec time1;
    struct timespec time2;
    uint32_t i = 0;

    while (TRUE) {
        clock_gettime(CLOCK_REALTIME, &time1);
        clock_gettime(CLOCK_REALTIME, &time2);

        if (time1.tv_sec == time2.tv_sec) {
            if (time2.tv_nsec < time1.tv_nsec) {
                PRINTF("Violation!\n");
                PRINTF("%09u - %09u\n", time1.tv_sec, time1.tv_nsec);
                PRINTF("%09u - %09u\n", time2.tv_sec, time2.tv_nsec);
            }
        }

        i++;

        if (0 == (i % 1000)) {
            PRINTF("Completed %d iterations...\n", i);
        }
    }

</code snippet>

<output>

(gdb) run
Completed 1000 iterations...
Completed 2000 iterations...
Completed 3000 iterations...
Violation!
000000000 - 169994000
000000000 - 160002000
Completed 4000 iterations...
Completed 5000 iterations...
Completed 6000 iterations...
Violation!
000000000 - 409994000
000000000 - 400002000
Completed 7000 iterations...
Completed 8000 iterations...
Completed 9000 iterations...
Completed 10000 iterations...
Completed 11000 iterations...
Violation!
000000000 - 769993000
000000000 - 760001000

</output>

I'm running RTEMS 4.10.99 against the LEON3 (GR712RC) BSP.

Is this expected behavior, or am I doing something incorrectly?

No it is not expected.

What date did you pull the code? Is it up to date?

Thanks.

Scott

--

Scott Miller | 210-522-4249 | Senior Research Engineer | Southwest Research Institute
_______________________________________________
users mailing list
users at rtems.org<mailto:users at rtems.org>
http://lists.rtems.org/mailman/listinfo/users

--
Joel Sherrill, Ph.D.             Director of Research & Development
joel.sherrill at OARcorp.com<mailto:joel.sherrill at OARcorp.com>        On-Line Applications Research
Ask me about RTEMS: a free RTOS  Huntsville AL 35805
Support Available                (256) 722-9985

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.rtems.org/pipermail/users/attachments/20150623/bd5afa2e/attachment-0002.html>