[SOLVED] Timer interrupts inaccurate at first, inconsistent at various prescaler

While trying to generate pulses, few millisecs to few seconds apart using timer1 CTC interrupts, I noticed that
the timing accuracies are way off initially, inaccuracies are also affected by pre-scaler used. As a scope is not
available, I tried using millis() :-[ to measure a bunch of (practically empty) timer ISR calls.

Following test program repeatedly causes 10 ISR for a specific delay setup timer1 at 1024 prescaler
CTC mode and reports the total time taken on serial monitor. The pulse delay is set using “stepGap” variable,

Compile/Uploaded to ArduMega and open serial monitor to see results ( do this for each / any of the delay
values used below). Close serial monitor change value of “stepGap” and repeat again.

The “stepGap” values used were 30 (1.9ms) , 60(3.8 ms), 120, 7812 (0.5 sec), 1564 ( 1 sec), was expecting the total
time period to be off by 1-5 ms, however the first iteration of 10 pulses is way way off. What am I missing?
As the delay value is increased the total time taken over shoots by several 100’s of ms. Why does this happen?

volatile int stepsRequired = 10; //number of pulses required in one iteration

volatile unsigned int stepGap = 7812;//15624,30,60,120 ORC1A count at 1024 prescaler. Multiply with 64us to get timer period

volatile unsigned long lastRecTime = 0;

volatile byte once = 1;


void setup()
{
  Serial.begin(115200);
  sei();
}

void loop()
{
  //do once
  if(once == 1)
  {
    if((millis() - lastRecTime) > 1000) //some gap between reading
    {
      startPulsing();      
      once = 2;
    }
  }
  
  if(once == 3)
  {
    //create messages
    lastRecTime = millis()-lastRecTime;//give almost identical results even if the calculation happens inside ISR
    Serial.print((lastRecTime), DEC);
    Serial.print(" ms for ");
    stepsRequired = 10;
    Serial.print(stepsRequired,DEC);
    Serial.print(" pulses, Each pulse set for ");
    float pulse_time = ((stepGap+1)*0.064);
    Serial.print(pulse_time , 2);
    Serial.print(" ms (Total) ");
    Serial.println(pulse_time*10 , 2);
    lastRecTime = millis();
    //once = 4;//stop after one run
    once = 1; // so that we can start all over again
  }
}

void startPulsing()
{
    //start the timers
    //TCNT1 = 0;
    TCCR1A = 0;
    TCCR1B = 0;
    OCR1B = 0;
    OCR1A = stepGap;    
    TIFR1 = 0;//reset any previous unserviced interrupts        
    lastRecTime = millis(); //store the starting count
    TCCR1B |= (1<<WGM12);//enable CTC Mode
    TIMSK1 |= (1<<OCIE1A) ;
    TCCR1B |= (1<<CS12) | (1<<CS10); //1024 prescaler  , counting starts here
}


ISR(TIMER1_COMPA_vect)
{
  //sei(); // incase the millis is stuck due to this ISR//no effect
      
  //check if more steps are required
  if(stepsRequired < 1)
  {
      //if not stop timer
      //TIMSK1 = 0 ;
      TCCR1B = 0; // if prescaler bits are set to 0 then counting stops
      //TCCR1A = 0;
      //OCR1A = 0;
      //OCR1B = 0;
      //TCNT1 = 0;
      
      once = 3;
      //lastRecTime = millis()-lastRecTime;//dosent make much of a diferrence in result if done here or out side      
  }
  else
  {
    //reduce counter
    stepsRequired--;
  }
}

for stepGap = 30 (1.9ms period)
4212 ms for 10 pulses, Each pulse set for 1.98 ms (Total) 19.84
22 ms for 10 pulses, Each pulse set for 1.98 ms (Total) 19.84
22 ms for 10 pulses, Each pulse set for 1.98 ms (Total) 19.84
22 ms for 10 pulses, Each pulse set for 1.98 ms (Total) 19.84
22 ms for 10 pulses, Each pulse set for 1.98 ms (Total) 19.84

for stepGap = 15624 (1 s period)
9997 ms for 10 pulses, Each pulse set for 1000.00 ms (Total) 10000.00
11000 ms for 10 pulses, Each pulse set for 1000.00 ms (Total) 10000.00
11000 ms for 10 pulses, Each pulse set for 1000.00 ms (Total) 10000.00
11000 ms for 10 pulses, Each pulse set for 1000.00 ms (Total) 10000.00

Set the counter registers OCR1A/B after starting the timer.

@jboton

modified and moved ORC1A setup after setting the clock source

void startPulsing()
{
    //start the timers
    //TCNT1 = 0;
    TCCR1A = 0;
    TCCR1B = 0;
    OCR1B = 0;
    [s]//OCR1A = stepGap;[/s]
    OCR1A = 0;
    TIFR1 = 0;//reset any previous unserviced interrupts        
    lastRecTime = millis(); //store the starting count
    TCCR1B |= (1<<WGM12);//enable CTC Mode
    TIMSK1 |= (1<<OCIE1A) ;
    TCCR1B |= (1<<CS12) | (1<<CS10); //1024 prescaler  , counting starts here
    OCR1A = stepGap;
}

no improvement. also ran on a different mega board. No change

Sorry, I was thinking of something else.

edit: In your ISR you're counting to 11 instead of 10. But that doesn't explain why the first time period is wonky.

volatile unsigned long lastRecTime = 0;

Change to:

volatile unsigned long lastRecTime = millis();

I tried the above suggestions, which didn’t help with the core problem. Then I started reworking quite a few things, for a while without success. Finally this works:

const int STEPS = 10;
volatile int stepsRequired = 0; //number of pulses required in one iteration
volatile unsigned int stepGap = 7812;//15624,30,60,120 ORC1A count at 1024 prescaler. Multiply with 64us to get timer period
volatile unsigned long lastRecTime = 0;
volatile unsigned long elapsedTime;
volatile boolean done = false;

void setup()
{
  Serial.begin(115200);
  GTCCR |= bit (PSRSYNC);  // reset prescaler
  startPulsing();      
}

void loop()
{
 
  if(done)
    {
    //create messages
    Serial.print(elapsedTime);
    Serial.print(" ms for ");
    Serial.print(STEPS);
    Serial.print(" pulses, Each pulse set for ");
    float pulse_time = ((stepGap + 1.0) * 0.064);
    Serial.print(pulse_time, 4);
    Serial.print(" ms (Total) ");
    Serial.println(pulse_time*10 , 4);
    done = false; // so that we can start all over again
    delay (1000);
    startPulsing();      
  }
}

void startPulsing()
{
    //start the timers
    noInterrupts ();
    stepsRequired = STEPS;
    TCCR1A = 0;  // stop timer
    TCCR1B = 0;
    OCR1A = stepGap;    
    TIFR1 = bit (OCF1A); //reset any previous unserviced interrupts        
    TIMSK1 = bit (OCIE1A);
    TCCR1B = bit (WGM12) | bit (CS10) | bit (CS12);//enable CTC Mode
    interrupts ();
    lastRecTime = millis(); //store the starting count
}


ISR(TIMER1_COMPA_vect)
{
  //check if more steps are required
  if(--stepsRequired < 1)
    {
    TCCR1B = 0; // if prescaler bits are set to 0 then counting stops
    elapsedTime = millis() - lastRecTime;
    done = true;
    }
}

Results:

4999 ms for 10 pulses, Each pulse set for 500.0320 ms (Total) 5000.3203
5000 ms for 10 pulses, Each pulse set for 500.0320 ms (Total) 5000.3203
5000 ms for 10 pulses, Each pulse set for 500.0320 ms (Total) 5000.3203
5000 ms for 10 pulses, Each pulse set for 500.0320 ms (Total) 5000.3203
5000 ms for 10 pulses, Each pulse set for 500.0320 ms (Total) 5000.3203
5000 ms for 10 pulses, Each pulse set for 500.0320 ms (Total) 5000.3203
5000 ms for 10 pulses, Each pulse set for 500.0320 ms (Total) 5000.3203
5001 ms for 10 pulses, Each pulse set for 500.0320 ms (Total) 5000.3203
5000 ms for 10 pulses, Each pulse set for 500.0320 ms (Total) 5000.3203
5000 ms for 10 pulses, Each pulse set for 500.0320 ms (Total) 5000.3203
5001 ms for 10 pulses, Each pulse set for 500.0320 ms (Total) 5000.3203

I got rid of your rather humorously named "once" variable:

  //do once
  if(once == 1)
  {
    if((millis() - lastRecTime) > 1000) //some gap between reading
    {
      startPulsing();      
      once = 2;
    }
  }
  
  if(once == 3)

A "once" variable shouldn't really have three or more states. It is either once, or it isna.

@Nick
Thank you for a wonderful analysis, I learned about GTCCR today. The decrement of “stepsRequired” was definitely causing an extra ISR call making a mess of total time. As for the TIFR1 = bit (OCF1A); shouldnt the bit be reset?

But the problem still remains. I do not want to invoke startPulsing in setup, so made three tiny changes

  1. Removed the startPulsing invocation from setup
  2. Changed done to true at initialization so startPulsing could be invoked after some time
  3. Reduced the stepGap value (as this bug does not seem to happen with large values)
const int STEPS = 10;
volatile int stepsRequired = 0; //number of pulses required in one iteration
volatile unsigned int stepGap = 30;//15624, 7812,30,60,120 ORC1A count at 1024 prescaler.
volatile unsigned long lastRecTime = 0;
volatile unsigned long elapsedTime;
volatile boolean done = true;

void setup()
{
  Serial.begin(115200);
  GTCCR |= bit (PSRSYNC);  // reset prescaler
  //startPulsing();      
}

void loop()
{
 
  if(done)
  {
    //create messages
    Serial.print(elapsedTime);
    Serial.print(" ms for ");
    Serial.print(STEPS);
    Serial.print(" pulses, Each pulse set for ");
    float pulse_time = ((stepGap + 1.0) * 0.064);
    Serial.print(pulse_time, 4);
    Serial.print(" ms (Total) ");
    Serial.println(pulse_time*10 , 4);
    done = false; // so that we can start all over again
    delay (1000);
    startPulsing();      
  }
}

void startPulsing()
{
    //start the timers
    noInterrupts ();
    stepsRequired = STEPS;
    TCCR1A = 0;  // stop timer
    TCCR1B = 0;
    OCR1A = stepGap;    
    TIFR1 = bit (OCF1A); //reset any previous unserviced interrupts        
    TIMSK1 = bit (OCIE1A);
    TCCR1B = bit (WGM12) | bit (CS10) | bit (CS12);//enable CTC Mode
    interrupts ();
    lastRecTime = millis(); //store the starting count
}


ISR(TIMER1_COMPA_vect)
{
  //check if more steps are required
  if(--stepsRequired < 1)
    {
    TCCR1B = 0; // if prescaler bits are set to 0 then counting stops
    elapsedTime = millis() - lastRecTime;
    done = true;
    }
}

This results in startPulsing being called in the loop after some delay ( which has to be the cause), a spurious first debug line is also produced, This can be safely ignored.

and the result

0 ms for 10 pulses, Each pulse set for 1.9840 ms (Total) 19.8400 ----- Ignore, cause the ISR was not invoked
4205 ms for 10 pulses, Each pulse set for 1.9840 ms (Total) 19.8400
20 ms for 10 pulses, Each pulse set for 1.9840 ms (Total) 19.8400
20 ms for 10 pulses, Each pulse set for 1.9840 ms (Total) 19.8400
20 ms for 10 pulses, Each pulse set for 1.9840 ms (Total) 19.8400
20 ms for 10 pulses, Each pulse set for 1.9840 ms (Total) 19.8400
20 ms for 10 pulses, Each pulse set for 1.9840 ms (Total) 19.8400
19 ms for 10 pulses, Each pulse set for 1.9840 ms (Total) 19.8400
19 ms for 10 pulses, Each pulse set for 1.9840 ms (Total) 19.8400
19 ms for 10 pulses, Each pulse set for 1.9840 ms (Total) 19.8400

OCFnA can be cleared by writing a logic one to its bit location. Atmega 2560 datasheet pge 168 para 2....missed it

TIFR1 = bit (OCF1A); is good

samit_ray is correct (as was my code). That particular flag is cleared by writing 1 to it. That lets you write 0 to some flags (and not clear them) and 1 to other flags (and clear them). That is rather specific to interrupt detection flags. Normally, of course, you write to a flag what you want in it.

Change startPulsing to clear TCNT1:

void startPulsing()
{
    //start the timers
    noInterrupts ();
    stepsRequired = STEPS;
    TCCR1A = 0;  // stop timer
    TCCR1B = 0;
    TCNT1 = 0;    // <---------------- clear the timer
    TIFR1 = bit (OCF1A); //reset any previous unserviced interrupts        
    TIMSK1 = bit (OCIE1A);
    TCCR1B = bit (WGM12) | bit (CS10) | bit (CS12);//enable CTC Mode
    OCR1A = stepGap;    
    interrupts ();
    lastRecTime = millis(); //store the starting count
}

Results:

0 ms for 10 pulses, Each pulse set for 1.9840 ms (Total) 19.8400
20 ms for 10 pulses, Each pulse set for 1.9840 ms (Total) 19.8400
20 ms for 10 pulses, Each pulse set for 1.9840 ms (Total) 19.8400
20 ms for 10 pulses, Each pulse set for 1.9840 ms (Total) 19.8400
20 ms for 10 pulses, Each pulse set for 1.9840 ms (Total) 19.8400
20 ms for 10 pulses, Each pulse set for 1.9840 ms (Total) 19.8400
19 ms for 10 pulses, Each pulse set for 1.9840 ms (Total) 19.8400
19 ms for 10 pulses, Each pulse set for 1.9840 ms (Total) 19.8400
19 ms for 10 pulses, Each pulse set for 1.9840 ms (Total) 19.8400
19 ms for 10 pulses, Each pulse set for 1.9840 ms (Total) 19.8400
19 ms for 10 pulses, Each pulse set for 1.9840 ms (Total) 19.8400
19 ms for 10 pulses, Each pulse set for 1.9840 ms (Total) 19.8400
20 ms for 10 pulses, Each pulse set for 1.9840 ms (Total) 19.8400
20 ms for 10 pulses, Each pulse set for 1.9840 ms (Total) 19.8400

The explanation is, I think, that the init() code (called automatically) which sets up the timers, starts Timer 1. Thus it is running by the time you get to it, and will have overshot 30. Now once it overshoots, it has to count around (rollover) to the next 30, and since it can count up to 65535 that accounts for the lengthy delay first time around.

That maybe a valid reason, lesson learnt... when using timers

  1. stop counting ( reset the prescalers bits CSn0:3)
  2. Reset TCNT and TIFR

then go about setting up everything for the timer.

@Nick - I owe you a home cooked bengali dinner, if you ever land up in India/Mumbai you dinner will be waiting.... :)

Thank you very much! :)

  1. ... ( reset the prescalers)

I'm not sure about that part, I was getting desperate when I did that. The prescaler is shared with Timer 0, and may affect the millis calculations. Still, it's useful to know you have the option.

I meant reset prescaler bits in TCCR (CSn0:3)