Improving millis()

((timer0_overflow_count << 8) + tcnt0) * 4 returns a number that is in tight correspondance with what is returned from millis(), at least after 20 minutes of running. I'm not sure what 976 is, but <<8 is *256 and *4 makes it 1024, which is what timer0_overflow_count represents.

Yep, I shouldn't post before having my morning coffee :wink:

I have a solution for extended millis period before rollover (tested on my arduino + EthernetShield webserver for uptime purpose) :

unsigned long millis()
{
//old version: return timer0_overflow_count * 64UL * 2UL / (F_CPU / 128000UL);

//new version:
return timer0_overflow_count * 128UL / (F_CPU / 128000UL)+(timer0_overflow_count>>25)*34359738UL;
//34359738 is 2^25 * 1.024
}

the problem was the loss of the 7 most significant bits caused by multiplying by 128 ("64UL * 2UL" in the original millis),
the effective number of bits of the original method was 25, so we had only 9hr between rollovers.
the solution is to compute the lowest 25 bits normally and compensate for the "lost bits" (with the "(timer0_overflow_count>>25)*34359738UL" part).
you now have a rollover of ~49days :sunglasses:

note: It is designed for a 16MHz avr, it may need modifications for other frequencies.

I've been working on something like the following in arduino (which is probably going to break in 0012).

Just FYI, I've worked around my issues (using custom ISR on timer 2) so you don't need to wait on me to release version 0012 ;D

Hey, this is a great thread. I thought I had made a clever discovery when I noticed the interrupt/millis() problem in my code, but I see you guys have already been talking about it for some time.

From bens

The odds of this happening are quite low, so this bug would manifest itself as an exceedingly rare and almost impossible-to-duplicate run-time error in code that relies on millis() for timing.

I did a little informal statistical test just now which seems to suggest that the probability of the interrupt firing at just the wrong time is about 1 in 600,000, which is indeed "exceedingly rare", but frequent enough, in my opinion, to warrant fixing.

Thanks!

Mikal

The odds of this happening are quite low, so this bug would manifest itself as an exceedingly rare and almost impossible-to-duplicate run-time error in code that relies on millis() for timing.

bens,

This interrupt problem actually appears to be more common that we might have guessed. In a little experiment I concocted this morning with delay(), which, as you know, relies on millis(), I discovered that roughly 1 in 1500 calls fails. By this I mean that if 10<=n<=200, then about 1 in 1500 calls to delay(n) will actually return much (at least 5%) too early as evidenced by this dump:

Wanted to delay 51ms, actually delayed 11ms (1 errors in 412 loops).
Wanted to delay 112ms, actually delayed 31ms (2 errors in 3405 loops).
Wanted to delay 187ms, actually delayed 67ms (3 errors in 3571 loops).
Wanted to delay 66ms, actually delayed 23ms (4 errors in 4406 loops).
Wanted to delay 143ms, actually delayed 95ms (5 errors in 6650 loops).
Wanted to delay 96ms, actually delayed 88ms (6 errors in 9114 loops).
Wanted to delay 73ms, actually delayed 66ms (7 errors in 10649 loops).
Wanted to delay 45ms, actually delayed 39ms (8 errors in 13095 loops).
Wanted to delay 195ms, actually delayed 32ms (9 errors in 13643 loops).
Wanted to delay 162ms, actually delayed 25ms (10 errors in 14017 loops).

Hopefully this doesn't come across as pedantic, but it would certainly seem to be further evidence that the interrupt problem should be addressed. The users of my new Arduino Pacemaker prototype will be grateful. :slight_smile:

Mikal

Dear all--

I would very much enjoy some feedback on the following. The lmillis() function posted below behaves (nearly) identically to millis() v. 0011, but is free from the "interrupt corruption problem" (see discussion above) and, most importantly, has a ~4.5 million year rollover. For those applications that struggle to deal with rollover, whether at 9 hours or 49 days, this might this be handy to have around-- not as a replacement for, but a companion to, millis().

PROS

  • Not subject to the "interrupt" problem that occasionally corrupts the millis() return
  • No practical rollover - 2^57 clock ticks ~= 4.5 million years.
  • Behaves the same as millis() and returns identical values up to the millis() rollover
  • Can coexist with the "normal" millis()
  • Doesn't require any modification to the timer overflow interrupt handler
  • Works on any AVR architecture that supports millis() and 8-byte long longs
    CONS- Uses unsigned long long type, which carries some baggage:
  • Return type not strictly compatible with millis(): cannot be Serial.print()ed directly for example
  • Long long math adds some bulk to most programs- High performance apps may not appreciate that it consumes more CPU than millis()
  • Must be called at least once every 49 days to ensure that overflow is not missed
  • Relies on v. 0011 millis implementation details
extern volatile unsigned long timer0_overflow_count;

unsigned long long lmillis()
{
  unsigned long toc;
  static unsigned long last_toc = 0UL;

  // This 8-byte value stores the overflow from timer0_overflow_count
  // in its 4 high-order bytes
  static unsigned long long overflow_overflow = 0ULL;

  // Clear interrupts to avoid millis() corruption problem
  uint8_t oldSREG = SREG;
  cli();

  // Safely get the current value of timer0_overflow_count
  toc = timer0_overflow_count;

  // Retore interrupts
  SREG = oldSREG;
  
  // If the newest value for timer0_overflow_count is less than the
  // previous value, then an overflow has occurred; increment accordingly
  // NOTE: this will only work if lmillis() is called at least once every 
  // 2^32 clocks, i.e. 49 days
  if (toc < last_toc)
    overflow_overflow += 0x100000000ULL;
  last_toc = toc;
  
  // Use the same formula that millis() uses to convert the tick count
  return (overflow_overflow + toc) * 64ULL * 2ULL / (F_CPU / 128000ULL);
}

It's easy to write a test program that demonstrates the correct behavior of lmillis(). I would like to share this with a wider audience, for example those on the playground hoping for an easy workaround to the rollover problem, but I thought I would bounce it off the smart people in this thread first. :slight_smile:

Regards,

Mikal

I would very much enjoy some feedback on the following...

Hi Mikal,

That approach may become obsolete when the next version of the Arduino is released. There is a solution posted in [u]reply three[/u] of this thread that overflows cleanly and is proposed for inclusion in version 0012. It works well and is easy to extend to prevent rollover if required (for example, the seconds counter in the DateTime library in the playground rolls over after 30 years using a long, and does not require touching any interrupts.)

Hi mem,

Thanks for the feedback. I absolutely agree that one of the shortcomings of this lmillis() is that it relies in 011 implementation details. I guess I was mostly thinking of it as a stopgap until 012 is released, but I do rather like having a function that absolutely reports the number of milliseconds without any practical rollover. (One of my current projects involving long time stretches and I like to be able to easily calculate precise time deltas up to a year.)

Perhaps lmillis() might be useful to the handful of playground folks who clamor for a[n immediate] solution to the rollover issue.

I have been reading this thread with great interest. It's a very satisfying read. Thanks for the good work, mellis, mem, bens, and everyone. I'm sure we are all looking forward to 012.

Mikal

Hi mem,

Thanks for the feedback. I absolutely agree that one of the shortcomings of this lmillis() is that it relies in 011 implementation details. I guess I was mostly thinking of it as a stopgap until 012 is released, but I do rather like having a function that absolutely reports the number of milliseconds without any practical rollover. (One of my current projects involving long time stretches and I like to be able to easily calculate precise time deltas up to a year.)

Perhaps lmillis() might be useful to the handful of playground folks who clamor for a[n immediate] solution to the rollover issue.

I have been reading this thread with great interest. It's a very satisfying read. Thanks for the good work, mellis, mem, bens, and everyone. I'm sure we are all looking forward to 012.

Mikal

The arduino crystal is accurate to around a few seconds per day so for long time deltas there is no benefit in using a precision greater than one second. You could therefore use either the technique posted in reply #8 of this thread, or replace the code in wiring .c with the code mellis posted in reply #3. My DateTime library uses the latter and works great.

If you don't want the whole DateTime library, you can use somethinglike the following:

unsigned long now() // return the elapsed seconds since system start
// rolls over in 2038
{
static unsigned long sysTime;
static unsigned long prevMillis;

  while( millis() - prevMillis >= 1000){
    sysTime++;
    prevMillis += 1000;
  }
  return sysTime;
}

mem,

(I gather from previous entries in this thread that you are aware that the above now() is broken in 011 because it requires millis() to overflow at 2^32 bits? It doesn't correctly handle the 9-hour rollover. Ah, that's why you're borrowing the 012 millis... got it.)

In any case, I would suggest replacing now()'s loop with something like the following. This should be somewhat faster, especially for programs that only call it occasionally.

unsigned long now() // return the elapsed seconds since system start 
{ 
  static unsigned long sysTime; 
  static unsigned long prevMillis; 
  unsigned long m = millis(); 
  if (m - prevMillis >= 1000) 
  { 
    unsigned long secs = (m - prevMillis) / 1000; 
    sysTime += secs; 
    prevMillis += secs * 1000; 
  } 
  return sysTime; 
}

Best regards,

Mikal

PS I like your library. Thanks for sharing.

M

PPS Why does the comment say that now() rolls over in 2038? Doesn't it roll over at 2^32 seconds? By my calculation that's ~136 years from power on...?

M

... I would suggest replacing now()'s loop with something like the following. This should be somewhat faster, especially for programs that only call it occasionally.

unsigned long now() // return the elapsed seconds since system start 

{
 static unsigned long sysTime;
 static unsigned long prevMillis;
 unsigned long m = millis();
 if (m - prevMillis >= 1000)
 {
   unsigned long secs = (m - prevMillis) / 1000;
   sysTime += secs;
   prevMillis += secs * 1000;
 }
 return sysTime;
}




PPS Why does the comment say that now() rolls over in 2038? Doesn't it roll over at 2^32 seconds? By my calculation that's ~136 years from power on...?

Hi Mikal,

If you are calling now() very infrequently than the version that multiplies and divides longs may be faster, but in most cases where now is called frequently, the version that adds and subtracts longs will be faster. Because there will be at least a second between the calculations, the affect on overall processing time for either version is not significant, so I will stick with the version that is a few bytes smaller.

Now() rolls over at 2038 in the DateTime library if sysTime is set for today's date using unix time. You are quite correct about the rollover if the sysTime starts at zero

Good morning, mem.

It's quite correct to optimize for the most common case. However, my anxiety stems from the point that in that worst case, now() requires upwards of three minutes (~187 seconds) just to calculate the time. This obviously is the wacky case in which the function is called after 49 days, but consider that even if you call now() once an hour, you'll expect to wait ~150ms for it to complete all its looping. This is enough of a delay, for example, to completely throw all your servo motors out of whack. I think that most developers expect a time-reporting type function to perform in pseudo-constant time.

I fear I have caused this topic to drift a bit. :slight_smile: Apologies, all! Thanks for the discussion, mem. Topics like this really stimulate the ol' brain box.

Cheers,

Mikal

Hi Mikal,

How are you measuring the time, I get just under 20ms using the following fragment to simulate the affect of now() needing to loop for an hours worth of seconds:

unsigned long now() {

for(int i = 0; i < 3600; i++){
millis();
sysTime++;
prevMillis += 1000;
}
return sysTime;
}

void loop(){
startMillis = millis();
now();
int dur = millis() - startMillis;
}

Although 20ms can be a relatively a long time to wait, I am having trouble thinking of why you wouldn't poll the function every minute or so if not every second.

If you really do need to wait hours or days to check an elapsed time, IMO its best to modify the interrupt handler to increment a seconds counter on each overflow as per the post earlier in this thread.

Hi mem.

If you temporarily change the initial value of prevMillis to something like:

static unsigned long prevMillis = 1000;

and then just call now(), this simulates the "worst case", which I imagine is something like the situation you'd see after 49 days. Since this took ~187 seconds, I calculated the one hour of "drift" would take proportionally less, i.e. 187s/49days/24hours = ~157ms.

I did some similar experiments to the one you excerpt above, and after getting astonishingly quick times (1ms!), I realized that that too-smart-for-its-own-good compiler is cleverly optimizing out the call to millis()! If you modify your test slightly to something like

for(int i = 0; i < 3600; i++)
{ 
  if (millis() == 0xDEADBEEF)
    Serial.println("Foo");
  sysTime++; 
  prevMillis += 1000; 
}

you'll get the 150ms figure.

That said, I'm in complete agreement that most apps would probably call now() so frequently as to not notice. But there are some out there that will break. I wouldn't like that. And I respectfully disagree that the best strategy to find out what time the sunlight hits your sensor is to have to write a new interrupt handler. That's what we have DateTime::now() for!!
:slight_smile:

Mikal

Millis doesn't roll over cleanly so I am not sure what your test is doing, but the code I ran isn't being optimized out. Here is the actual code that the compiler produced for the test that I ran:

unsigned long now() // return the elapsed seconds since system start
    1626:      cf 93             push      r28
    1628:      df 93             push      r29
    162a:      c0 e0             ldi      r28, 0x00      ; 0
    162c:      d0 e0             ldi      r29, 0x00      ; 0
{

  for(int i = 0; i < 3600; i++){
    millis();
    162e:      0e 94 e2 0c       call      0x19c4      ; 0x19c4 <millis>
    sysTime++;
    1632:      20 91 17 01       lds      r18, 0x0117
    1636:      30 91 18 01       lds      r19, 0x0118
    163a:      40 91 19 01       lds      r20, 0x0119
    163e:      50 91 1a 01       lds      r21, 0x011A
    1642:      2f 5f             subi      r18, 0xFF      ; 255
    1644:      3f 4f             sbci      r19, 0xFF      ; 255
    1646:      4f 4f             sbci      r20, 0xFF      ; 255
    1648:      5f 4f             sbci      r21, 0xFF      ; 255
    164a:      20 93 17 01       sts      0x0117, r18
    164e:      30 93 18 01       sts      0x0118, r19
    1652:      40 93 19 01       sts      0x0119, r20
    1656:      50 93 1a 01       sts      0x011A, r21
    prevMillis += 1000;
    165a:      80 91 1b 01       lds      r24, 0x011B
    165e:      90 91 1c 01       lds      r25, 0x011C
    1662:      a0 91 1d 01       lds      r26, 0x011D
    1666:      b0 91 1e 01       lds      r27, 0x011E
    166a:      88 51             subi      r24, 0x18      ; 24
    166c:      9c 4f             sbci      r25, 0xFC      ; 252
    166e:      af 4f             sbci      r26, 0xFF      ; 255
    1670:      bf 4f             sbci      r27, 0xFF      ; 255
    1672:      80 93 1b 01       sts      0x011B, r24
    1676:      90 93 1c 01       sts      0x011C, r25
    167a:      a0 93 1d 01       sts      0x011D, r26
    167e:      b0 93 1e 01       sts      0x011E, r27
    1682:      21 96             adiw      r28, 0x01      ; 1
    1684:      8e e0             ldi      r24, 0x0E      ; 14
    1686:      c0 31             cpi      r28, 0x10      ; 16
    1688:      d8 07             cpc      r29, r24
    168a:      89 f6             brne      .-94           ; 0x162e <_Z3nowv+0x8>
  }
  return sysTime;

There is a significant performance hit on making a function call so your call to Serial.println() probably takes much more time than all the other code in the function (my guess is 130ms of the 150ms you measured is spent doing the Serial.println call.

Anyway, although we are getting quite different measurements, I don't think we are really disagreeing on the principles being discussed here.

Have fun!

Ah, no, no! My sample code never calls Serial.println at all (because millis() is never equal to 0xDEADBEEF)!

I am puzzled why your results differ so much. Even when I run your test code -- the one I incorrectly presumed was being optimized -- I still get ~157ms. May I ask what you get when you run this program -- which is just your code with a diagnostic thrown in?

static unsigned long sysTime;  
static unsigned long prevMillis;  
  
unsigned long now() { 
 
  for(int i = 0; i < 3600; i++){ 
    millis(); 
    sysTime++; 
    prevMillis += 1000; 
  } 
  return sysTime; 
}  
 
void  loop(){ 
  long startMillis = millis(); 
  now();   
  int dur = millis() - startMillis; 
  Serial.println(dur);
} 

void setup()
{
  Serial.begin(9600);
}

I consistently get ~157-164ms. If you are getting 20ms, I wonder if you have some better optimizations going? Can you point me to a document that describes how to produce a disassembly? I really want to learn how to do that.

Cheers, and thanks much!

Mikal

I get 19 and 20 when running that code.

I am running Arduino version 0011 with the default compiler settings but with wiring.c modified with the 0012 millis() code as posted earlier in this thread.

You can view the assembler by running a utility called avr-objdump.exe on the elf file. There is a thread that discusses how to do it here: http://www.arduino.cc/cgi-bin/yabb2/YaBB.pl?num=1207951658

Ah, yes! That makes a lot of sense. Since the v. 012 version of millis() is so much simpler than its v. 011 counterpart, your results are very understandable. Thanks!

Mikal