system_timer_current_time_us drifts behind us_ticker_read at a variable rate

[martinwork]

system_timer_current_time_us loses time relative to us_ticker_read at a variable rate. This affects system_timer_current_time and uBit.systemTime. The drift is usually 1.5 to 4.5 ms/s, but can be higher. Very occasionally, system_timer suddenly catches up by about 60ms.

Reading the system_timer more often speeds up the drift. I suspect interrupts occurring inside update_time cause ticks to be dropped.

This could be improved by only resetting the Timer when timer->read_us() > 2000000000.

Maybe a better solution is to ditch Timer and use us_ticker_read directly?

The example below sends to serial, when button A is clicked or B held down, the times, the difference between them and the rate of drift in microseconds per second.

#include "MicroBit.h"
#include "MicroBitCompat.h"

MicroBit uBit;

uint64_t sys0;
uint64_t sys1;
uint64_t sys;

uint64_t tic0;
uint64_t tic1;
uint64_t tic;

int64_t dif;
double speed;
uint64_t uspers;

void sendTimes()
{
  sys1 = system_timer_current_time_us();
  tic1 = us_ticker_read();

  sys  = sys1 - sys0;
  tic  = tic1 - tic0;

  // difference between us_ticker_read and system_timer_current_time_us
  dif = tic >= sys ? tic - sys : -(sys - tic);

  // calculate drift in us/s
  speed = (double)dif / (double)tic;
  uspers = speed * 1000000.0;

  ManagedString st( (int)tic);
  ManagedString ss( (int)sys);
  ManagedString sd( (int)dif);
  ManagedString sv( (int)uspers);

  ManagedString s = st + "," + ss + "," + sd + "," + sv + "\n";

  uBit.serial.send( s);
}

void onButtonA(MicroBitEvent)
{
  sendTimes();
}

void onButtonB(MicroBitEvent)
{
  while ( uBit.buttonB.isPressed())
  {
    uBit.sleep(10);
    sendTimes();
  }
}

int main()
{
  uBit.init();

  uBit.serial.send( "\n\ntick,sys,tick-sys,speed (us/s)\n");

  sys0 = system_timer_current_time_us();
  tic0 = us_ticker_read();

  sys = 0;
  tic = 0;
  dif = 0;

  uBit.serial.send( "\n\n");

  uBit.messageBus.listen( MICROBIT_ID_BUTTON_A, MICROBIT_BUTTON_EVT_CLICK, onButtonA);
  uBit.messageBus.listen( MICROBIT_ID_BUTTON_B, MICROBIT_BUTTON_EVT_DOWN, onButtonB);

  release_fiber();
}

[martinwork]

Another test. Sends to serial, the difference between system_timer_current_time_us() and time calculated by counting system ticks. Also shows error when measuring the time between pressing button A and pressing a button at P0, similar to MakeCode measuring a sonar pulse.

Fix is in PR #469

drift.zip

#include "MicroBit.h"

MicroBit uBit;

class TickCounter : MicroBitComponent
{
public:
    uint64_t us0;
    uint64_t usSent;
    uint64_t count0;
    uint64_t count;

    TickCounter()
    {
        us0 = system_timer_current_time_us();
        usSent = 0;
        count0 = 0;
        count = 0;
        system_timer_add_component( this);
        uBit.addIdleComponent( this);
    }

    ~TickCounter()
    {
        uBit.removeIdleComponent( this);
        system_timer_remove_component( this);
    }

    void systemTick()
    {
        count++;
    }

    void idleTick()
    {
        uBit.display.image.setPixelValue( 0, 0, uBit.display.image.getPixelValue( 0, 0) ? 0 : 255);

        if ( system_timer_current_time_us() - usSent >= 10000000ul)
            sendTime();
    }

    void sendTime()
    {
        uint64_t usNow = system_timer_current_time_us();
        usSent = usNow;

        uint64_t dt = usNow - us0;
        uint64_t dc = ( count - count0) * SYSTEM_TICK_PERIOD_MS * 1000;

        int diff;

        if ( dt >= dc)
            diff = ( dt - dc + 999) / 1000;
        else
            diff = - ( ( dc - dt + 999) / 1000);

        int u  = dt % 1000000ul; dt /= 1000000ul;
        int s  = dt % 60;        dt /= 60;
        int m  = dt % 60;        dt /= 60;
        int h  = dt % 24;        dt /= 24;
        int d  = dt;
        ManagedString sep = " : ";
        ManagedString dot = " . ";
        ManagedString aft = "ms after ";
        ManagedString su( u);
        ManagedString ss( s);
        ManagedString sm( m);
        ManagedString sh( h);
        ManagedString sd( d);
        ManagedString sdiff( diff);
        ManagedString msg = sdiff + aft + sd + sep + sh + sep + sm + sep + ss + dot + su;
#if CONFIG_ENABLED(MICROBIT_DBG)
        if(SERIAL_DEBUG) SERIAL_DEBUG->printf("\n%s", msg.toCharArray());
#endif
    }
};

TickCounter *tickCounter;

void onButtonA(MicroBitEvent e)
{
    uint64_t time0 = system_timer_current_time_us();
    uint64_t count0 = tickCounter->count;

    uint64_t count = count0;
    uint64_t time  = time0;

    while ( !uBit.io.P0.getDigitalValue())
    {
        count = tickCounter->count;
        time = system_timer_current_time_us();

        if ( time - time0 > 10000000ul)
            break;
    }

    uint64_t dc = ( count - count0) * SYSTEM_TICK_PERIOD_MS * 1000;
    uint64_t dt = time - time0;

    int diff;

    if ( dt >= dc)
        diff = ( dt - dc + 999) / 1000;
    else
        diff = - ( ( dc - dt + 999) / 1000);

    ManagedString s( diff);
    uBit.display.scrollAsync( s);
}

int main()
{
    // Initialise the micro:bit runtime.
    uBit.init();

    tickCounter = new TickCounter();

    uBit.messageBus.listen(MICROBIT_ID_BUTTON_A, MICROBIT_BUTTON_EVT_DOWN, onButtonA);

    uBit.display.print( '.');

    // If main exits, there may still be other fibers running or registered event handlers etc.
    // Simply release this fiber, which will mean we enter the scheduler. Worse case, we then
    // sit in the idle task forever, in a power efficient sleep.
    release_fiber();
}