Error in micros()

Hi all.
I'm seeing a weird bug in micros() behavior.
The micros() sometimes is stuck or even goes backward.
I saw in 2009 a similar bug was discovered and fixed but I still have that problem. I'm using the IDE 1.8.5 and I checked that that bug is fixed in wiring.c
I'm using arduino mega.

To reproduce.
Good behavior code:

const byte PPM_pin = 2;
volatile unsigned long t0 = 0; //previous time
volatile unsigned long t = 0; //actual time
volatile unsigned delta_t = 0; //difference time

void setup() {
  // put your setup code here, to run once:
  Serial.begin(57600);
  pinMode(PPM_pin, INPUT);
  t0 = micros();
  attachInterrupt(0, ppm_reader, RISING); //on pin 2
}

void loop() {
}

void ppm_reader() {
  t = micros();
  Serial.print("Time actual: ");
  Serial.println(micros());  
}

What I see printed is the correct:

Time actual: 51628
Time actual: 51960
Time actual: 51264
Time actual: 51592
Time actual: 51920
Time actual: 53272
Time actual: 53600

Bad behavior code (only adding a println in the interrupt handler):

const byte PPM_pin = 2;
volatile unsigned long t0 = 0; //previous time
volatile unsigned long t = 0; //actual time
volatile unsigned delta_t = 0; //difference time

void setup() {
  // put your setup code here, to run once:
  Serial.begin(57600);
  pinMode(PPM_pin, INPUT);
  t0 = micros();
  attachInterrupt(0, ppm_reader, RISING); //on pin 2
}

void loop() {
}

void ppm_reader() {
  t = micros();
  Serial.print("Time actual: ");
  Serial.println(micros());
  Serial.println("Testtttttttt");  //<---- extra line

}

What I see in the serial is:

Time actual: 6168
Testtttttttt
Time actual: 6656
Testtttttttt
Time actual: 7148
Testtttttttt
Time actual: 6612
Testtttttttt
Time actual: 7104
Testtttttttt
Time actual: 6568
Testtttttttt
Time actual: 7060
Testtttttttt
Time actual: 6524
Testtttttttt
Time actual: 7016
Testtttttttt
Time actual: 6480

So micros() is getting stuck and going backward...only for one println extra in the ISR oO.

Bad behavior code (only adding a println in the interrupt handler):

That's not bad, it's stupid.

Don't do Serial output (or input!) in interrupt handlers.

I wasn't doing it, it was for debug only. Even without Serial I was having weird behavior.
And can you explain why using serial in the interrupt generates that unwanted behavior? I'm not doing anything weird with timers or whatever. It shouldn't behave like that for sure.

I suspect you are spending more than 1ms inside your ISR, thus missing timer0 interrupts, which will
cause the symptoms you see.

How often is the PPM_pin toggling? Perhaps you are continuously re-entering the pin interrupt and
thus blocking any timer interrupt? Pin interrupts are very high priority.

I suspect you are spending more than 1ms inside your ISR, thus missing timer0 interrupts, which will
cause the symptoms you see.

Good answer

That's not bad, it's stupid.

Bad answer

MarkT:
I suspect you are spending more than 1ms inside your ISR, thus missing timer0 interrupts, which will
cause the symptoms you see.

How often is the PPM_pin toggling? Perhaps you are continuously re-entering the pin interrupt and
thus blocking any timer interrupt? Pin interrupts are very high priority.

Thanks.
Why spending more than 1ms in the ISR can make me miss timer0 interrupts? Are the interrupt and the micros() using and sharing the same timer?
The PPM interrupt is around every 300 us.

Are the interrupt and the micros() using and sharing the same timer?

An interrupt handler responds to an event. It does not "use a timer".

But, the clock ticking generates interrupts that cause the clock-tick interrupt handler to update the value that micros() returns.

If your ISR prevents the clock-tick interrupt handler from executing often enough, the value that micros() returns will be inaccurate.

PaulS:
An interrupt handler responds to an event. It does not "use a timer".

But, the clock ticking generates interrupts that cause the clock-tick interrupt handler to update the value that micros() returns.

If your ISR prevents the clock-tick interrupt handler from executing often enough, the value that micros() returns will be inaccurate.

Ok, I can understand that it can lag behind, but going backward? I think it's something else here.

Have you taken stuff that doesn't belong in an interrupt handler, out of the interrupt handler?
If the answer is yes, what are your observations?
If the answer is no . . . why not?

What is generating the interrupt pulse every 300 microseconds?

@tuloski, you are not testing micros(), you have written bad code which has a bad result. I agree with @CtrlAltElite that the code is stupid ::slight_smile: Using Serial functions in a ISR is wrong. Also, if the Serial.println puts out too many bytes and it can not keep up with the interrupts, then anything can happen.
There is a bug in the sketch. You may not use a 4-byte variable that is written in a ISR on a 8-bit microcontroller like that. The interrupts have to be turned off to use that variable.

I did a small test. In this test I don't even try to keep up with the interrupts. Every 500 ms the difference is printed, which should be about 500000 µs. The result is pretty good, no glitches, just as expected.

// Test with micros
// ----------------
// Arduino Mega 2560 with Arduino IDE 1.8.5
// Pin 2 is connected to pin 3.
// Pin 3 has a frequency output with tone() which uses an interrupt.
//

volatile unsigned long t;

unsigned long previous_t;
unsigned long previousMillis;

void setup()
{
  Serial.begin( 115200);
  Serial.println(F( "Start..."));

  attachInterrupt( digitalPinToInterrupt( 2), ppm_reader, RISING);   // on pin 2
  tone( 3, 5000);        // frequency output on pin 3
}

void loop()
{
  // The Arduino Mega 2560 uses a 8-bit ATmega chip.
  // That means reading or writing a unsigned long can be interrupted.
  noInterrupts();
  unsigned long t_copy = t;
  interrupts();

  if( millis() - previousMillis >= 500)
  {
    previousMillis = millis();

    unsigned long delta = t_copy - previous_t;
    Serial.println( delta);
    previous_t = t_copy;
  }
}

void ppm_reader()
{
  t = micros();
}

the code is stupid

Code can't be stupid. People can be. If you know that something is bound to fail and do it anyway... you can be called stupid. But not being aware that some functions are not compatible to some tasks does not qualify anybody to be called stupid.

Using Serial functions in a ISR is wrong.

But that, of course, is to the point, relevant and worth mentionning.

Ok, I did bad code, but can anyone explain why if the ISR takes too long than "ANYTHING CAN HAPPEN" as repeated by many people? What could happen?

And why can't I use the unsigned long in the interrupt? Another interrupt shouldn't stop the previous interrupt. They are put in queue.

No-one (I hope) said you can't use a uint32_t in an interrupt - the problem is handling that value outside of the interrupt.
When you access it, you need to protect the access by disabling interrupts before you either read from it or write to it, then reenable interrupts. That goes for any variable bigger than a byte.

Koepel wrote: "There is a bug in the sketch. You may not use a 4-byte variable that is written in a ISR on a 8-bit microcontroller like that. The interrupts have to be turned off to use that variable."

But I didn't use the variable in the loop, only in the ISR.

But I didn't use the variable in the loop, only in the ISR.

In that case, it is difficult to see what the point of the variable is.

CtrlAltElite:
In that case, it is difficult to see what the point of the variable is.

It was just debugging, but I'd like to understand what is going on, especially for future use of ISR and micros().

micros() uses timer0, hardware so the only problem I see is when the overflow interrupt of timer0 happens (every 1,024 milliseconds). But still the interrupts should be queued, not dropped, so I don't see how micros() can return values going backward oO.

I don't see how micros() can return values going backward oO.

And until I see a clear, credible, repeatable demonstration, neither will I.

CtrlAltElite:
And until I see a clear, credible, repeatable demonstration, neither will I.

There is my code in the initial post.

tuloski:
There is my code in the initial post.

I wrote "clear, credible, repeatable"