RTC Appears to Be Way Out of Expected Timing

One last issue to crack. This one has been in production for a while and hasn't caused any issues other than a little annoyance to the customer.

By my measurement when RTC is used to count down from 4.00 at 2:55 it will be at 1:55 approx. So basically 4/2 instead of 4/3, or 1/4 faster running than it should be.

I run an RTC for a task runner I wrote. It's clock is initially started using RC. Shortly after and during what I'm about to describe BLE is running and so LFCLK is synthesised by the 16MHz crystal, managed by softdevice. I don't think the issue is here.


#define CFG_SCHEDULER_TIMER_PRESCALER 4
#define CFG_SCHEDULER_TIMER_HZTICKS (32768U/CFG_SCHEDULER_TIMER_PRESCALER)
#define CFG_SCHEDULER_TIMER_MSEC_TICKS (CFG_SCHEDULER_TIMER_HZTICKS/1000)

CFG_SCHEDULER_TIMER->PRESCALER = CFG_SCHEDULER_TIMER_PRESCALER-1;


As you can see I'm generating a tick at 8192Hz.

So half these ticks gives me a 2Hz task runner (which for some reason appears to be at about 3Hz!)

struct schedulerProto scheduler = {
  .slots[SCHEDULER_TIMER_SLOT_2HZ].ticks = CFG_SCHEDULER_TIMER_HZTICKS/2
};


There's a bunch of tasks which can issue some small delay inbetween tasks, but come rain or shine the runner will be looping at the 2Hz tick value. The tasks thus can't run any longer than the 500ms before the next cycle, and they're nowhere near so it isn't that. One of the tasks has a simple coundown, which goes out by BLE and that's how I found the timing to be way off.

  scheduler.slots[SCHEDULER_TIMER_SLOT_2HZ].loop = 1;
  scheduler.slots[SCHEDULER_TIMER_SLOT_2HZ].tasks.list[0] = ...
  scheduler.slots[SCHEDULER_TIMER_SLOT_2HZ].tasks.list[1] = ...
  scheduler.slots[SCHEDULER_TIMER_SLOT_2HZ].tasks.list[2] = ...
  scheduler.slots[SCHEDULER_TIMER_SLOT_2HZ].tasks.list[3] = ...
  scheduler.slots[SCHEDULER_TIMER_SLOT_2HZ].tasks.list[4] = &resetWatchdog;
  scheduler.slots[SCHEDULER_TIMER_SLOT_2HZ].tasks.last = &scheduler.slots[SCHEDULER_TIMER_SLOT_2HZ].tasks.list[4];


Start running...

SCHEDULER_CreateFromNow(SCHEDULER_TIMER_SLOT_2HZ, scheduler.slots[SCHEDULER_TIMER_SLOT_2HZ].ticks);



Which calls this. The key here is it's getting the counter value and adding the 500ms amount of ticks.

static void createUsingTicks (uint8_t id, uint32_t ticks) {

  // RTC is 24 bit
  if (ticks > (1 << 24)-1) {
    ticks -= (1 << 24)-1;
  }
  CFG_SCHEDULER_TIMER->CC[id] = ticks;
}

/*
 * Used by looping tasks, does not change the interrupt state
 */
void SCHEDULER_CreateFromNowNoInterrupt(uint8_t id, uint32_t ticks) {

  ticks += CFG_SCHEDULER_TIMER->COUNTER;
  createUsingTicks(id, ticks);
}

/* 
 * Used for starting a looping tasks and non looping tasks
 */
void SCHEDULER_CreateFromNow(uint8_t id, uint32_t ticks) {

  CFG_SCHEDULER_TIMER->EVENTS_COMPARE[id] = 0;
  (void)CFG_SCHEDULER_TIMER->EVENTS_COMPARE[id];
  SCHEDULER_CreateFromNowNoInterrupt(id, ticks);
  CFG_SCHEDULER_TIMER->INTENSET = RTC_INTENSET_COMPARE0_Set << (RTC_INTENSET_COMPARE0_Pos + id);
}


The interrupt fires...

void CFG_SCHEDULER_TIMER_IRQ_HANDLER (void) {

  if (CFG_SCHEDULER_TIMER->EVENTS_COMPARE[SCHEDULER_TIMER_SLOT_2HZ]) {
    CFG_SCHEDULER_TIMER->EVENTS_COMPARE[SCHEDULER_TIMER_SLOT_2HZ] = RTC_EVENTS_COMPARE_EVENTS_COMPARE_NotGenerated;
    handle(SCHEDULER_TIMER_SLOT_2HZ);
  }
}

And here's the code which goes through the tasks. You can see how it stores the initial counter value at the beginning so I'm not adding the 500ms to what the counter is at when all the tasks are complete but when the first initially started.

static void handle(uint8_t id) {

  struct schedulerSlotProto *slot = &scheduler.slots[id];

  if (!slot->running) {
    slot->timestamp = CFG_SCHEDULER_TIMER->COUNTER;
    slot->running = 1;
  }
  while (1) {
    if (slot->done) {
      slot->tasks.next = &slot->tasks.list[0];
      if (slot->loop) {
        createUsingTicks(id, slot->timestamp + slot->ticks);
      } else {
        CFG_SCHEDULER_TIMER->INTENCLR = RTC_INTENCLR_COMPARE0_Clear << (RTC_INTENCLR_COMPARE0_Pos + id);
      }
      slot->running = 0;
      slot->done = 0;
      break;
    }
    uint32_t ticks = (*slot->tasks.next)();
    if (*slot->tasks.next == *slot->tasks.last) {
      slot->count++;
      slot->done = 1;
    } else {
      *slot->tasks.next++;
    }
    if (ticks) {
      SCHEDULER_CreateFromNowNoInterrupt(id, ticks);
      break;
    }
  }
}


I can't think of anything. I thought if the interrupt was slow to be serviced that would slow the point at which the counter value is captured, which would slow the timing down. What I'm seeing is the opposite!

Cheers!

Andrew

Parents
  • I have it!

    After some better timing I discovered it was double.

    What's happening is I clear the event at the start of the interrupt, but because the counter is still the same as the compare it immediately refires. Then it dives into the tasks which change the compare value, however the event has already set and it enters the interrupt one more time. Now the compare is different so the clear works.

    It's probably related to this errata, though I'm not using PPI. It can also be put down to the sync of different clock domains of course, something I shall have to watch out for in the future.

    // errata 179 - docs.nordicsemi.com/.../anomaly_810_179.html


Reply
  • I have it!

    After some better timing I discovered it was double.

    What's happening is I clear the event at the start of the interrupt, but because the counter is still the same as the compare it immediately refires. Then it dives into the tasks which change the compare value, however the event has already set and it enters the interrupt one more time. Now the compare is different so the clear works.

    It's probably related to this errata, though I'm not using PPI. It can also be put down to the sync of different clock domains of course, something I shall have to watch out for in the future.

    // errata 179 - docs.nordicsemi.com/.../anomaly_810_179.html


Children
No Data
Related