millis() gives strange results

Projects Programming
1

Hello there,

I'm trying to measure the frame rate of a led installation (3x5meter ws2812 strips) where an arduino MEGA receives UDP packets from my mac and activate the pixels using adafruit Neopixel Library.

I'm using this code in my main loop to count the frames :

void loop(){

... READ THE UDP PACKET...
... ACTIVATE THE PIXELS WITH strip.setPixelColor() ...

      nbframes++;
      if (nbframes>500){ //counting every 500 packets
        now = millis();
        Serial.println(now) ;
        Serial.println( 500/ (float(now-lastUpdated)/1000) );
        nbframes=0;
        lastUpdated=millis();
      }

strip.show();


}

the problem is when the arduino says 3 seconds has past, I can count 9 seconds in the real world ! so i cannot have precise frames per second.
If I comment the "strip.show" line, the problem disappear.
Something must happen in the adafruit library that prevents millis from counting well. I've read that arduino millis() is not affected by other function since it's using interrupts. So what can it be ?

Could I use another way to count my framerate while displaying the pixels ?

here is the output of the Arduino serial port, using a shell "cat" to have timestamps (sorry for the french time formats )

18001, Ven 10 jul 2015 17:24:26 CEST
164, Ven 10 jul 2015 17:24:37 CEST
21047, Ven 10 jul 2015 17:24:37 CEST
164, Ven 10 jul 2015 17:24:48 CEST
24093, Ven 10 jul 2015 17:24:48 CEST
164, Ven 10 jul 2015 17:24:59 CEST
27140, Ven 10 jul 2015 17:24:59 CEST
164, Ven 10 jul 2015 17:25:10 CEST
30185, Ven 10 jul 2015 17:25:10 CEST
164, Ven 10 jul 2015 17:25:21 CEST
33231, Ven 10 jul 2015 17:25:21 CEST
164, Ven 10 jul 2015 17:25:32 CEST
36275, Ven 10 jul 2015 17:25:32 CEST
164, Ven 10 jul 2015 17:25:43 CEST
39319, Ven 10 jul 2015 17:25:43 CEST
164, Ven 10 jul 2015 17:25:54 CEST
42364, Ven 10 jul 2015 17:25:54 CEST
164, Ven 10 jul 2015 17:26:05 CEST
45410, Ven 10 jul 2015 17:26:05 CEST

Thanks for your help

Ben.

3

The adafruit neopixel library turns interrupts off and runs a block of hand-tuned assembly to blast out the data. Because interrupts are off, it can miss the timer0 overflow interrupts which are used to advance the millisecond counter.

That's what I think is happening. You can probably make the issue far less severe by not calling it as often as you can like you do now - why refresh it when there's no change? Sending the data takes a non-zero length of time - several milliseconds for a string of even modest length, though, so this will always be an issue doing it like this. You might be able to work around it using an RTC, or periodically checking a url for current time

You might also try a different library (like fastled) and see if that does any better - but I think they'll all have the same issue; you need to update the millisecond counter every millisecond, but if you've got a time-sensitive process that takes 2+ milliseconds (the WS2812 protocol is time sensitive), millis is going to get out of sync.

I think you could (since you know how many millis you lose with each call) manually add that many to the value of timer0_millis, but you need to disable interupts while doing so, to avoid corrupting it if the millis tick happens then, ie:

strip.show();
uint8_t oldSREG = SREG;
cli();
timer0_millis+=2; //assuming it's 2ms that you lose per show.
SREG = oldSREG;

But I don't think this does what you want, because you would need to know how many milliseconds each frame takes, which I think is what you're trying to figure out here...

4

The adafruit neopixel library turns interrupts off and runs a block of hand-tuned assembly to blast out the data. Because interrupts are off, it can miss the timer0 overflow interrupts which are used to advance the millisecond counter.

Yes, adafruit should learn to be a bit more professional with their software.

5

odometer:
Yes, adafruit should learn to be a bit more professional with their software.

It's free. It's a starting point. You don't have to use it.

6

odometer:
Yes, adafruit should learn to be a bit more professional with their software.

The neopixel LEDs have tight timing requirements, so interrupts must be turned off while the software sends data to them.

7

The adafruit neopixel library turns interrupts off and runs a block of hand-tuned assembly to blast out the data. Because interrupts are off, it can miss the timer0 overflow interrupts which are used to advance the millisecond counter.

It being assembly, I wonder how hard it would be to determine the number of cycles to run it and then compensate the millisecond counter at the end.

the problem is when the arduino says 3 seconds has past, I can count 9 seconds in the real world !
...
Could I use another way to count my framerate while displaying the pixels ?

If it were my problem to solve, I would use a separate timing device (such as a mechanical chronograph) to measure the time. I would change the LED color once every, let's say 100 frames, and then I would count the "hundreds" of frames in one minute. Then I would modify the code to change the color, say, once every 50 frames, and then time it again, just to check the result from the first run.

here is the output of the Arduino serial port, using a shell "cat" to have timestamps (sorry for the french time formats )

Don't apologize for the French timestamps. At least I can understand them.
On these forums, there are a lot of posts I can't make sense out of, even when they are in English.

18001, Ven 10 jul 2015 17:24:26 CEST
164, Ven 10 jul 2015 17:24:37 CEST
21047, Ven 10 jul 2015 17:24:37 CEST
164, Ven 10 jul 2015 17:24:48 CEST
24093, Ven 10 jul 2015 17:24:48 CEST
164, Ven 10 jul 2015 17:24:59 CEST
27140, Ven 10 jul 2015 17:24:59 CEST
164, Ven 10 jul 2015 17:25:10 CEST
...

By the way, your interval looks like 11 seconds, not 9 seconds.

8

odometer:
It being assembly, I wonder how hard it would be to determine the number of cycles to run it and then compensate the millisecond counter at the end.

The problem there is you're asking the question "Did Timer0 overflow while I wasn't looking?" Since you weren't looking, you don't know if it did.

Most interrupts will be queued so that they will be run after interrupts are re-enabled. (This is the only time that the priority of interrupts matters.) But if it overflowed twice while you weren't looking there's no way to distinguish that.

9

MorganS:
But if it overflowed twice while you weren't looking there's no way to distinguish that.

I think you might be able to get a pretty good approximation.

The timer 0 overflows every 2^14 clock cycles. So if you could accurately count the number of cycles that occur with interrupts disabled you could estimate the number of missed overflows with (cycles>>14)-1, or zero if this results in a negative number. It's an estimate because there is latency in responding to an interrupt that is impossible to predict with certainty. So it wouldn't be perfect, but it might work pretty well. Kind of a kludge though.

10

Is Timer 1 free? If so, with a prescaler of 1024 each count will be 64 uS, and since it can count up to 65536 you could use it to time an interval of 4.194 seconds in hardware, which does not rely on interrupts. Example code:

void startTimer1 ()
  {
  // reset Timer 1
  TCCR1A = 0;
  TCCR1B = 0;
  // zero it
  TCNT1 = 0;  
  TIFR1 |= bit (TOV1);  // clear overflow flag
  // start Timer 1
  TCCR1B =  bit (CS10) | bit (CS12);  //  prescaler of 1024
  }  // end of startTimer1
  
unsigned long getTimer1Reading ()
  {
  unsigned long elapsed = TCNT1;
  if (TIFR1 &  bit (TOV1))
     elapsed += 65536;
  return elapsed;    
  }  // end of getTimer1Reading
  
void setup ()
  {
  Serial.begin (115200);
  Serial.println ();

  }  // end of setup

void loop ()
  {
  Serial.println ("Starting ...");
  Serial.flush ();

  startTimer1 ();
  
  delay (7560);
  float secs = (1.0 / F_CPU * 1024) * getTimer1Reading ();

  Serial.print ("Time taken = ");
  Serial.print (secs);
  Serial.println (" seconds.");

  }  // end of loop

This will successfully time up to just under 8.388 seconds. After that we miss an overflow, and it will read too low.

The example just uses delay() to test, but would work with interrupts off.

Example of timing with interrupts off (first part omitted):

volatile byte x;

void loop ()
  {
  Serial.println ("Starting ...");
  Serial.flush ();
  
  startTimer1 ();
  
  noInterrupts ();
  for (unsigned long i = 0; i < 5000000; i++)
    if (x == 1)
     break;
  interrupts ();
  
  float secs = (1.0 / F_CPU * 1024)  * getTimer1Reading ();

  Serial.print ("Time taken = ");
  Serial.print (secs);
  Serial.println (" seconds.");

  }  // end of loop
11

MorganS:

odometer:
The problem there is you're asking the question "Did Timer0 overflow while I wasn't looking?" Since you weren't looking, you don't know if it did.

Most interrupts will be queued so that they will be run after interrupts are re-enabled. (This is the only time that the priority of interrupts matters.) But if it overflowed twice while you weren't looking there's no way to distinguish that.

No, what I mean is you look at the assembly code and you add up the cycles. You know that there are 16 cycles in a microsecond, and 1000 microseconds in a millisecond 1024 microseconds per millis() interrupt. From that, you can calculate how many interrupts you will have missed.

That said, I think that my "mechanical chronograph" method would be a good backup. And by that I mean:

Gallet broad arrow ww1 1915 [Public domain], by Time Maven at en.wikipedia (Transferred from en.wikipedia by Ronhjones), from Wikimedia Commons

12

So let me get this straight: Odometer is recommending a Chronometer?

13

Yes, preferably a trippy one like this:

(Disclaimer: this is not for actual timekeeping.)

14

Cool, the roll-over at midnight was great!

15

I made a (kind of) real one here:
http://robsmisc.com/css-clock-demo.php

How many hours is my clock ahead of / behind your wristwatch cell phone? (Oh yeah, this is the year 2015, people don't wear watches anymore.)
The thing is 3 h 59 min 42 s ahead of my wristwatch (yes, I know, I need a better watch.)

16

Wow.

17

"Wow" does not parse as a number.

18

Thank you for the enlightening discussion.
I have to admit I've used the word "interrupts" without understanding what I was speaking about. I understand that Neopixels is messing up the way millis() is counting time, and I can either add a RTC or using a watch and count manually. Or maybe request time on my mac on another serial port.

B.

19

What was wrong with my suggestion about using Timer 1?

20

Would timer1 not also be effected if they stop and start interupts?

21

Sorry Nick I've misread your first post and thaught it was not applicable.
I've just add your functions and rewrote my timing code like this :

      nbframes++;
      if (nbframes>150){ // counting every 150 packets
//         now = millis();
          float secs = (1.0 / F_CPU * 1024) * getTimer1Reading ();
          Serial.println(secs);
          Serial.println( 150/ secs );
          nbframes=0;
          startTimer1 ();
//        lastUpdated=millis();
      }

and .. it works !

I read 6.82 seconds on the serial port and 6.84 on my manually controlled stopwatch but hey..

(Strangely my shell "cat" on my mac don't want to show decimals. )

Thank you