[RTEMS Project] #1748: SPARC BSPs nanoseconds skipping back when counter wraps during get TOD or uptime call

[RTEMS trac]

#1748: SPARC BSPs nanoseconds skipping back when counter wraps during get TOD or
uptime call
-----------------------------+----------------------------
 Reporter:  rolf.schroedter  |       Owner:  joel.sherrill
     Type:  defect           |      Status:  closed
 Priority:  normal           |   Milestone:  4.10
Component:  bsps             |     Version:  4.10
 Severity:  normal           |  Resolution:  fixed
 Keywords:                   |
-----------------------------+----------------------------
Changes (by joel.sherrill):

 * version:  unknown => 4.10


Old description:

> I'm running RTEMS on a LEON3 (sparc) platform.
> It's downloaded from Gaisler and claims to be
>      rtems-4.9.99.0(SPARC/w/FPU/leon3)
>
> The function rtems_clock_get_uptime() fails when it
> is called during a timer tick. In this case a single time value is
> wrong, the time is skipping backwards by 1 millisecond (TICK). The next
> call returns a correct time.
>
> The problem can be demonstrated using the following code, storing the
> original return of rtems_clock_get_uptime() in an array and calculating a
> microsecond value from that return. At the end all time values are
> printed showing the problem:
>
> Code:
> RTEMS running with 1 millisecond TICK.
> {
>     #define LOOPS 1000
>
>     int          i;
>     uint32_t     uptime_usec[LOOPS], t0=0;
>     struct timespec    uptime[LOOPS];
>
>     for ( i=0; i<LOOPS; i++ )
>     {
>     rtems_clock_get_uptime( &uptime[i] );
>     uptime_usec[i] = ((uint32_t)uptime[i].tv_sec * 1000000) +
> ((uint32_t)uptime[i].tv_nsec / 1000);
>     }
>     for ( i=0; i<LOOPS; i++ )
>     {
>     unsigned t1, usec, msec, sec;
>
>     t1 = uptime_usec[i];
>     usec = t1 % 1000;
>     msec = (t1 / 1000) % 1000;
>     sec  = t1 / 1000000;
>
>     printf("TEST:rtems=%u.%09u   t=%u.%03u.%03u   dt=%u\n",
> uptime[i].tv_sec, uptime[i].tv_nsec, sec, msec, usec, (t1-t0));
>     t0 = t1;
>     }
> }
>

> Output:
> - Lines #616 and #686 show the time skipping backwards.
> - The nanoseconds uptime shows that rtems_clock_get_uptime() has
> probably been called during a clock TICK.
>
> 000: uptime=0.445817000   sec=0.445.817   dt=445817
> 001: uptime=0.445835000   sec=0.445.835   dt=18
> 002: uptime=0.445849000   sec=0.445.849   dt=14
> 003: uptime=0.445863000   sec=0.445.863   dt=14
> ...
> 616: uptime=0.454973000   sec=0.454.973   dt=14
> 617: uptime=0.454988000   sec=0.454.988   dt=15
> 618: uptime=0.454002000   sec=0.454.002   dt=4294966310
> 619: uptime=0.455042000   sec=0.455.042   dt=1040
> 620: uptime=0.455056000   sec=0.455.056   dt=14
> 621: uptime=0.455070000   sec=0.455.070   dt=14
> ...
> 684: uptime=0.455972000   sec=0.455.972   dt=14
> 685: uptime=0.455987000   sec=0.455.987   dt=15
> 686: uptime=0.455001000   sec=0.455.001   dt=4294966310
> 687: uptime=0.456042000   sec=0.456.042   dt=1041
> 688: uptime=0.456056000   sec=0.456.056   dt=14
> 689: uptime=0.456071000   sec=0.456.071   dt=15
> ...

New description:

 I'm running RTEMS on a LEON3 (sparc) platform.
 It's downloaded from Gaisler and claims to be
      rtems-4.9.99.0(SPARC/w/FPU/leon3)

 The function rtems_clock_get_uptime() fails when it
 is called during a timer tick. In this case a single time value is
 wrong, the time is skipping backwards by 1 millisecond (TICK). The next
 call returns a correct time.

 The problem can be demonstrated using the following code, storing the
 original return of rtems_clock_get_uptime() in an array and calculating a
 microsecond value from that return. At the end all time values are printed
 showing the problem:

 Code:
 RTEMS running with 1 millisecond TICK.
 {
     #define LOOPS 1000

     int          i;
     uint32_t     uptime_usec[LOOPS], t0=0;
     struct timespec    uptime[LOOPS];

     for ( i=0; i<LOOPS; i++ )
     {
     rtems_clock_get_uptime( &uptime[i] );
     uptime_usec[i] = ((uint32_t)uptime[i].tv_sec * 1000000) +
 ((uint32_t)uptime[i].tv_nsec / 1000);
     }
     for ( i=0; i<LOOPS; i++ )
     {
     unsigned t1, usec, msec, sec;

     t1 = uptime_usec[i];
     usec = t1 % 1000;
     msec = (t1 / 1000) % 1000;
     sec  = t1 / 1000000;

     printf("TEST:rtems=%u.%09u   t=%u.%03u.%03u   dt=%u\n",
 uptime[i].tv_sec, uptime[i].tv_nsec, sec, msec, usec, (t1-t0));
     t0 = t1;
     }
 }


 Output:
 - Lines #616 and #686 show the time skipping backwards.
 - The nanoseconds uptime shows that rtems_clock_get_uptime() has
 probably been called during a clock TICK.

 000: uptime=0.445817000   sec=0.445.817   dt=445817
 001: uptime=0.445835000   sec=0.445.835   dt=18
 002: uptime=0.445849000   sec=0.445.849   dt=14
 003: uptime=0.445863000   sec=0.445.863   dt=14
 ...
 616: uptime=0.454973000   sec=0.454.973   dt=14
 617: uptime=0.454988000   sec=0.454.988   dt=15
 618: uptime=0.454002000   sec=0.454.002   dt=4294966310
 619: uptime=0.455042000   sec=0.455.042   dt=1040
 620: uptime=0.455056000   sec=0.455.056   dt=14
 621: uptime=0.455070000   sec=0.455.070   dt=14
 ...
 684: uptime=0.455972000   sec=0.455.972   dt=14
 685: uptime=0.455987000   sec=0.455.987   dt=15
 686: uptime=0.455001000   sec=0.455.001   dt=4294966310
 687: uptime=0.456042000   sec=0.456.042   dt=1041
 688: uptime=0.456056000   sec=0.456.056   dt=14
 689: uptime=0.456071000   sec=0.456.071   dt=15
 ...

--

--
Ticket URL: <http://devel.rtems.org/ticket/1748#comment:6>
RTEMS Project <http://www.rtems.org/>
RTEMS Project